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

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

tests
0

failures
2

ignored
3.417s

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.278s passed
readsSparkSourceTestLenient[1](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.279s passed
readsSparkSourceTestSilent[0](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam, null) 0.216s passed
readsSparkSourceTestSilent[1](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.206s passed
readsSparkSourceTestStrict[0](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam, null) 0.031s passed
readsSparkSourceTestStrict[1](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.035s passed
readsSparkSourceTest[0](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam, null) 0.484s passed
readsSparkSourceTest[1](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.bam, null) 0.357s passed
readsSparkSourceTest[2](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/expected.HiSeq.1mb.1RG.2k_lines.alternate.recalibrated.DIQ.bam, null) 0.261s passed
readsSparkSourceTest[3](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.200s passed
readsSparkSourceTest[4](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/valid.cram, /gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/valid.fasta) 0.175s passed
readsSparkSourceUnknownHostTest 0.020s 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.248s passed
testCRAMReferenceFromHDFS - ignored
testCRAMReferenceRequired 0s passed
testCheckCRAMReference 0s passed
testGetHeader[0](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam, null) 0.046s passed
testGetHeader[1](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.bam, null) 0.032s passed
testGetHeader[2](/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/expected.HiSeq.1mb.1RG.2k_lines.alternate.recalibrated.DIQ.bam, null) 0.031s passed
testGetHeader[3](/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram, /gatkCloneMountPoint/src/test/resources/human_g1k_v37.chr17_1Mb.fasta) 0.027s 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.153s passed
testIntervals 0.116s passed
testIntervalsWithUnmapped 0.114s passed
testPartitionSizing 0.080s passed
testReadFromFileAndHDFS - ignored
testReject2BitCRAMReference 0s passed

Standard error

19:02:00.484 INFO  MemoryStore - Block broadcast_34 stored as values in memory (estimated size 297.2 KiB, free 1919.4 MiB)
19:02:00.510 INFO  MemoryStore - Block broadcast_34_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1919.4 MiB)
19:02:00.511 INFO  BlockManagerInfo - Added broadcast_34_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.9 MiB)
19:02:00.512 INFO  SparkContext - Created broadcast 34 from newAPIHadoopFile at PathSplitSource.java:96
19:02:00.590 INFO  MemoryStore - Block broadcast_35 stored as values in memory (estimated size 297.2 KiB, free 1919.1 MiB)
19:02:00.606 INFO  MemoryStore - Block broadcast_35_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1919.1 MiB)
19:02:00.606 INFO  BlockManagerInfo - Added broadcast_35_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.8 MiB)
19:02:00.607 INFO  SparkContext - Created broadcast 35 from newAPIHadoopFile at PathSplitSource.java:96
19:02:00.667 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
19:02:00.667 INFO  DAGScheduler - Got job 20 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
19:02:00.667 INFO  DAGScheduler - Final stage: ResultStage 29 (collect at ReadsSparkSourceUnitTest.java:111)
19:02:00.667 INFO  DAGScheduler - Parents of final stage: List()
19:02:00.667 INFO  DAGScheduler - Missing parents: List()
19:02:00.667 INFO  DAGScheduler - Submitting ResultStage 29 (ParallelCollectionRDD[69] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:00.669 INFO  MemoryStore - Block broadcast_36 stored as values in memory (estimated size 3.0 KiB, free 1919.1 MiB)
19:02:00.669 INFO  MemoryStore - Block broadcast_36_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1919.1 MiB)
19:02:00.670 INFO  BlockManagerInfo - Added broadcast_36_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1919.8 MiB)
19:02:00.670 INFO  SparkContext - Created broadcast 36 from broadcast at DAGScheduler.scala:1580
19:02:00.670 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))
19:02:00.670 INFO  TaskSchedulerImpl - Adding task set 29.0 with 4 tasks resource profile 0
19:02:00.672 INFO  TaskSetManager - Starting task 0.0 in stage 29.0 (TID 67) (localhost, executor driver, partition 0, PROCESS_LOCAL, 47080 bytes) 
19:02:00.673 INFO  TaskSetManager - Starting task 1.0 in stage 29.0 (TID 68) (localhost, executor driver, partition 1, PROCESS_LOCAL, 47194 bytes) 
19:02:00.674 INFO  TaskSetManager - Starting task 2.0 in stage 29.0 (TID 69) (localhost, executor driver, partition 2, PROCESS_LOCAL, 47105 bytes) 
19:02:00.675 INFO  TaskSetManager - Starting task 3.0 in stage 29.0 (TID 70) (localhost, executor driver, partition 3, PROCESS_LOCAL, 47530 bytes) 
19:02:00.676 INFO  Executor - Running task 0.0 in stage 29.0 (TID 67)
19:02:00.676 INFO  Executor - Running task 1.0 in stage 29.0 (TID 68)
19:02:00.676 INFO  Executor - Running task 3.0 in stage 29.0 (TID 70)
19:02:00.677 INFO  Executor - Running task 2.0 in stage 29.0 (TID 69)
19:02:00.685 INFO  Executor - Finished task 2.0 in stage 29.0 (TID 69). 40380 bytes result sent to driver
19:02:00.687 INFO  Executor - Finished task 0.0 in stage 29.0 (TID 67). 40355 bytes result sent to driver
19:02:00.688 INFO  Executor - Finished task 3.0 in stage 29.0 (TID 70). 40848 bytes result sent to driver
19:02:00.689 INFO  TaskSetManager - Finished task 2.0 in stage 29.0 (TID 69) in 16 ms on localhost (executor driver) (1/4)
19:02:00.690 INFO  TaskSetManager - Finished task 0.0 in stage 29.0 (TID 67) in 19 ms on localhost (executor driver) (2/4)
19:02:00.690 INFO  Executor - Finished task 1.0 in stage 29.0 (TID 68). 40469 bytes result sent to driver
19:02:00.691 INFO  TaskSetManager - Finished task 1.0 in stage 29.0 (TID 68) in 19 ms on localhost (executor driver) (3/4)
19:02:00.692 INFO  TaskSetManager - Finished task 3.0 in stage 29.0 (TID 70) in 18 ms on localhost (executor driver) (4/4)
19:02:00.692 INFO  TaskSchedulerImpl - Removed TaskSet 29.0, whose tasks have all completed, from pool 
19:02:00.692 INFO  DAGScheduler - ResultStage 29 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.024 s
19:02:00.693 INFO  DAGScheduler - Job 20 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:00.693 INFO  TaskSchedulerImpl - Killing all running tasks in stage 29: Stage finished
19:02:00.693 INFO  DAGScheduler - Job 20 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.026006 s
19:02:00.711 INFO  FileInputFormat - Total input files to process : 1
19:02:00.774 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
19:02:00.775 INFO  DAGScheduler - Got job 21 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
19:02:00.775 INFO  DAGScheduler - Final stage: ResultStage 30 (collect at ReadsSparkSourceUnitTest.java:112)
19:02:00.775 INFO  DAGScheduler - Parents of final stage: List()
19:02:00.775 INFO  DAGScheduler - Missing parents: List()
19:02:00.775 INFO  DAGScheduler - Submitting ResultStage 30 (MapPartitionsRDD[76] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:00.803 INFO  MemoryStore - Block broadcast_37 stored as values in memory (estimated size 425.0 KiB, free 1918.6 MiB)
19:02:00.804 INFO  MemoryStore - Block broadcast_37_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1918.5 MiB)
19:02:00.805 INFO  BlockManagerInfo - Added broadcast_37_piece0 in memory on localhost:45255 (size: 152.7 KiB, free: 1919.7 MiB)
19:02:00.805 INFO  SparkContext - Created broadcast 37 from broadcast at DAGScheduler.scala:1580
19:02:00.805 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))
19:02:00.805 INFO  TaskSchedulerImpl - Adding task set 30.0 with 1 tasks resource profile 0
19:02:00.811 INFO  TaskSetManager - Starting task 0.0 in stage 30.0 (TID 71) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7831 bytes) 
19:02:00.812 INFO  Executor - Running task 0.0 in stage 30.0 (TID 71)
19:02:00.869 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam:0+57538
19:02:00.884 INFO  Executor - Finished task 0.0 in stage 30.0 (TID 71). 159615 bytes result sent to driver
19:02:00.885 INFO  TaskSetManager - Finished task 0.0 in stage 30.0 (TID 71) in 79 ms on localhost (executor driver) (1/1)
19:02:00.885 INFO  TaskSchedulerImpl - Removed TaskSet 30.0, whose tasks have all completed, from pool 
19:02:00.886 INFO  DAGScheduler - ResultStage 30 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.108 s
19:02:00.886 INFO  DAGScheduler - Job 21 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:00.886 INFO  TaskSchedulerImpl - Killing all running tasks in stage 30: Stage finished
19:02:00.886 INFO  DAGScheduler - Job 21 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.111910 s
19:02:00.894 INFO  MemoryStore - Block broadcast_38 stored as values in memory (estimated size 297.3 KiB, free 1918.2 MiB)
19:02:00.904 INFO  MemoryStore - Block broadcast_38_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1918.1 MiB)
19:02:00.904 INFO  BlockManagerInfo - Added broadcast_38_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.6 MiB)
19:02:00.904 INFO  SparkContext - Created broadcast 38 from newAPIHadoopFile at PathSplitSource.java:96
19:02:00.946 INFO  BlockManagerInfo - Removed broadcast_31_piece0 on localhost:45255 in memory (size: 320.0 B, free: 1919.6 MiB)
19:02:00.956 INFO  BlockManagerInfo - Removed broadcast_14_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.6 MiB)
19:02:00.960 INFO  BlockManagerInfo - Removed broadcast_2_piece0 on localhost:45255 in memory (size: 349.0 B, free: 1919.6 MiB)
19:02:00.962 INFO  BlockManagerInfo - Removed broadcast_27_piece0 on localhost:45255 in memory (size: 5.1 KiB, free: 1919.6 MiB)
19:02:00.965 INFO  BlockManagerInfo - Removed broadcast_6_piece0 on localhost:45255 in memory (size: 5.0 KiB, free: 1919.6 MiB)
19:02:00.967 INFO  BlockManagerInfo - Removed broadcast_21_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.6 MiB)
19:02:00.970 INFO  BlockManagerInfo - Removed broadcast_30_piece0 on localhost:45255 in memory (size: 4.7 KiB, free: 1919.6 MiB)
19:02:00.972 INFO  MemoryStore - Block broadcast_39 stored as values in memory (estimated size 297.3 KiB, free 1917.9 MiB)
19:02:00.973 INFO  BlockManagerInfo - Removed broadcast_9_piece0 on localhost:45255 in memory (size: 4.7 KiB, free: 1919.6 MiB)
19:02:00.975 INFO  BlockManagerInfo - Removed broadcast_16_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.6 MiB)
19:02:00.982 INFO  BlockManager - Removing RDD 7
19:02:00.989 INFO  BlockManagerInfo - Removed broadcast_23_piece0 on localhost:45255 in memory (size: 465.0 B, free: 1919.6 MiB)
19:02:00.990 INFO  MemoryStore - Block broadcast_39_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1917.9 MiB)
19:02:00.990 INFO  BlockManagerInfo - Added broadcast_39_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.6 MiB)
19:02:00.991 INFO  SparkContext - Created broadcast 39 from newAPIHadoopFile at PathSplitSource.java:96
19:02:00.992 INFO  BlockManagerInfo - Removed broadcast_8_piece0 on localhost:45255 in memory (size: 3.8 KiB, free: 1919.6 MiB)
19:02:00.994 INFO  BlockManagerInfo - Removed broadcast_5_piece0 on localhost:45255 in memory (size: 3.2 KiB, free: 1919.6 MiB)
19:02:00.997 INFO  BlockManagerInfo - Removed broadcast_15_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.6 MiB)
19:02:01.001 INFO  BlockManagerInfo - Removed broadcast_1_piece0 on localhost:45255 in memory (size: 143.0 B, free: 1919.6 MiB)
19:02:01.004 INFO  BlockManagerInfo - Removed broadcast_34_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.6 MiB)
19:02:01.006 INFO  BlockManagerInfo - Removed broadcast_33_piece0 on localhost:45255 in memory (size: 4.8 KiB, free: 1919.7 MiB)
19:02:01.008 INFO  BlockManagerInfo - Removed broadcast_11_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.7 MiB)
19:02:01.009 INFO  BlockManager - Removing RDD 47
19:02:01.012 INFO  BlockManagerInfo - Removed broadcast_7_piece0 on localhost:45255 in memory (size: 326.0 B, free: 1919.7 MiB)
19:02:01.014 INFO  BlockManagerInfo - Removed broadcast_28_piece0 on localhost:45255 in memory (size: 320.0 B, free: 1919.7 MiB)
19:02:01.018 INFO  BlockManagerInfo - Removed broadcast_19_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.7 MiB)
19:02:01.020 INFO  BlockManagerInfo - Removed broadcast_29_piece0 on localhost:45255 in memory (size: 3.8 KiB, free: 1919.7 MiB)
19:02:01.023 INFO  BlockManagerInfo - Removed broadcast_0_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.7 MiB)
19:02:01.026 INFO  BlockManagerInfo - Removed broadcast_4_piece0 on localhost:45255 in memory (size: 4.5 KiB, free: 1919.7 MiB)
19:02:01.028 INFO  BlockManagerInfo - Removed broadcast_3_piece0 on localhost:45255 in memory (size: 4.3 KiB, free: 1919.7 MiB)
19:02:01.031 INFO  BlockManagerInfo - Removed broadcast_36_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.7 MiB)
19:02:01.034 INFO  BlockManagerInfo - Removed broadcast_32_piece0 on localhost:45255 in memory (size: 3.8 KiB, free: 1919.7 MiB)
19:02:01.035 INFO  BlockManagerInfo - Removed broadcast_26_piece0 on localhost:45255 in memory (size: 3.2 KiB, free: 1919.7 MiB)
19:02:01.036 INFO  BlockManagerInfo - Removed broadcast_17_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.7 MiB)
19:02:01.037 INFO  BlockManagerInfo - Removed broadcast_37_piece0 on localhost:45255 in memory (size: 152.7 KiB, free: 1919.8 MiB)
19:02:01.039 INFO  BlockManagerInfo - Removed broadcast_20_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.8 MiB)
19:02:01.040 INFO  BlockManagerInfo - Removed broadcast_22_piece0 on localhost:45255 in memory (size: 159.0 B, free: 1919.8 MiB)
19:02:01.041 INFO  BlockManagerInfo - Removed broadcast_10_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.8 MiB)
19:02:01.043 INFO  BlockManagerInfo - Removed broadcast_12_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.8 MiB)
19:02:01.044 INFO  BlockManagerInfo - Removed broadcast_35_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.9 MiB)
19:02:01.045 INFO  BlockManagerInfo - Removed broadcast_24_piece0 on localhost:45255 in memory (size: 4.3 KiB, free: 1919.9 MiB)
19:02:01.046 INFO  BlockManagerInfo - Removed broadcast_25_piece0 on localhost:45255 in memory (size: 4.5 KiB, free: 1919.9 MiB)
19:02:01.048 INFO  BlockManagerInfo - Removed broadcast_13_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.9 MiB)
19:02:01.049 INFO  BlockManagerInfo - Removed broadcast_18_piece0 on localhost:45255 in memory (size: 2.4 KiB, free: 1919.9 MiB)
19:02:01.052 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
19:02:01.052 INFO  DAGScheduler - Got job 22 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
19:02:01.053 INFO  DAGScheduler - Final stage: ResultStage 31 (collect at ReadsSparkSourceUnitTest.java:111)
19:02:01.053 INFO  DAGScheduler - Parents of final stage: List()
19:02:01.053 INFO  DAGScheduler - Missing parents: List()
19:02:01.053 INFO  DAGScheduler - Submitting ResultStage 31 (ParallelCollectionRDD[82] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:01.054 INFO  MemoryStore - Block broadcast_40 stored as values in memory (estimated size 3.0 KiB, free 1919.3 MiB)
19:02:01.055 INFO  MemoryStore - Block broadcast_40_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1919.3 MiB)
19:02:01.055 INFO  BlockManagerInfo - Added broadcast_40_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1919.9 MiB)
19:02:01.056 INFO  SparkContext - Created broadcast 40 from broadcast at DAGScheduler.scala:1580
19:02:01.056 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))
19:02:01.056 INFO  TaskSchedulerImpl - Adding task set 31.0 with 4 tasks resource profile 0
19:02:01.058 INFO  TaskSetManager - Starting task 0.0 in stage 31.0 (TID 72) (localhost, executor driver, partition 0, PROCESS_LOCAL, 169886 bytes) 
19:02:01.059 INFO  TaskSetManager - Starting task 1.0 in stage 31.0 (TID 73) (localhost, executor driver, partition 1, PROCESS_LOCAL, 170093 bytes) 
19:02:01.060 INFO  TaskSetManager - Starting task 2.0 in stage 31.0 (TID 74) (localhost, executor driver, partition 2, PROCESS_LOCAL, 170081 bytes) 
19:02:01.062 INFO  TaskSetManager - Starting task 3.0 in stage 31.0 (TID 75) (localhost, executor driver, partition 3, PROCESS_LOCAL, 169419 bytes) 
19:02:01.062 INFO  Executor - Running task 0.0 in stage 31.0 (TID 72)
19:02:01.062 INFO  Executor - Running task 1.0 in stage 31.0 (TID 73)
19:02:01.062 INFO  Executor - Running task 2.0 in stage 31.0 (TID 74)
19:02:01.062 INFO  Executor - Running task 3.0 in stage 31.0 (TID 75)
19:02:01.071 INFO  Executor - Finished task 1.0 in stage 31.0 (TID 73). 163411 bytes result sent to driver
19:02:01.072 INFO  Executor - Finished task 0.0 in stage 31.0 (TID 72). 163247 bytes result sent to driver
19:02:01.073 INFO  Executor - Finished task 2.0 in stage 31.0 (TID 74). 163442 bytes result sent to driver
19:02:01.074 INFO  TaskSetManager - Finished task 1.0 in stage 31.0 (TID 73) in 16 ms on localhost (executor driver) (1/4)
19:02:01.075 INFO  Executor - Finished task 3.0 in stage 31.0 (TID 75). 162780 bytes result sent to driver
19:02:01.077 INFO  TaskSetManager - Finished task 0.0 in stage 31.0 (TID 72) in 20 ms on localhost (executor driver) (2/4)
19:02:01.077 INFO  TaskSetManager - Finished task 2.0 in stage 31.0 (TID 74) in 18 ms on localhost (executor driver) (3/4)
19:02:01.077 INFO  TaskSetManager - Finished task 3.0 in stage 31.0 (TID 75) in 17 ms on localhost (executor driver) (4/4)
19:02:01.077 INFO  TaskSchedulerImpl - Removed TaskSet 31.0, whose tasks have all completed, from pool 
19:02:01.077 INFO  DAGScheduler - ResultStage 31 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.024 s
19:02:01.078 INFO  DAGScheduler - Job 22 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:01.078 INFO  TaskSchedulerImpl - Killing all running tasks in stage 31: Stage finished
19:02:01.078 INFO  DAGScheduler - Job 22 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.025630 s
19:02:01.080 INFO  FileInputFormat - Total input files to process : 1
19:02:01.137 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
19:02:01.138 INFO  DAGScheduler - Got job 23 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
19:02:01.138 INFO  DAGScheduler - Final stage: ResultStage 32 (collect at ReadsSparkSourceUnitTest.java:112)
19:02:01.138 INFO  DAGScheduler - Parents of final stage: List()
19:02:01.138 INFO  DAGScheduler - Missing parents: List()
19:02:01.139 INFO  DAGScheduler - Submitting ResultStage 32 (MapPartitionsRDD[89] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:01.162 INFO  MemoryStore - Block broadcast_41 stored as values in memory (estimated size 425.0 KiB, free 1918.9 MiB)
19:02:01.164 INFO  MemoryStore - Block broadcast_41_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1918.8 MiB)
19:02:01.164 INFO  BlockManagerInfo - Added broadcast_41_piece0 in memory on localhost:45255 (size: 152.7 KiB, free: 1919.8 MiB)
19:02:01.164 INFO  SparkContext - Created broadcast 41 from broadcast at DAGScheduler.scala:1580
19:02:01.165 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))
19:02:01.165 INFO  TaskSchedulerImpl - Adding task set 32.0 with 1 tasks resource profile 0
19:02:01.166 INFO  TaskSetManager - Starting task 0.0 in stage 32.0 (TID 76) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7875 bytes) 
19:02:01.166 INFO  Executor - Running task 0.0 in stage 32.0 (TID 76)
19:02:01.210 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.bam:0+221635
19:02:01.240 INFO  Executor - Finished task 0.0 in stage 32.0 (TID 76). 650184 bytes result sent to driver
19:02:01.242 INFO  TaskSetManager - Finished task 0.0 in stage 32.0 (TID 76) in 77 ms on localhost (executor driver) (1/1)
19:02:01.243 INFO  TaskSchedulerImpl - Removed TaskSet 32.0, whose tasks have all completed, from pool 
19:02:01.243 INFO  DAGScheduler - ResultStage 32 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.104 s
19:02:01.243 INFO  DAGScheduler - Job 23 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:01.243 INFO  TaskSchedulerImpl - Killing all running tasks in stage 32: Stage finished
19:02:01.243 INFO  DAGScheduler - Job 23 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.105564 s
19:02:01.252 INFO  MemoryStore - Block broadcast_42 stored as values in memory (estimated size 297.3 KiB, free 1918.5 MiB)
19:02:01.260 INFO  MemoryStore - Block broadcast_42_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1918.4 MiB)
19:02:01.260 INFO  BlockManagerInfo - Added broadcast_42_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.7 MiB)
19:02:01.260 INFO  SparkContext - Created broadcast 42 from newAPIHadoopFile at PathSplitSource.java:96
19:02:01.296 INFO  MemoryStore - Block broadcast_43 stored as values in memory (estimated size 297.3 KiB, free 1918.1 MiB)
19:02:01.307 INFO  MemoryStore - Block broadcast_43_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1918.1 MiB)
19:02:01.308 INFO  BlockManagerInfo - Added broadcast_43_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.7 MiB)
19:02:01.308 INFO  SparkContext - Created broadcast 43 from newAPIHadoopFile at PathSplitSource.java:96
19:02:01.341 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
19:02:01.342 INFO  DAGScheduler - Got job 24 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
19:02:01.342 INFO  DAGScheduler - Final stage: ResultStage 33 (collect at ReadsSparkSourceUnitTest.java:111)
19:02:01.342 INFO  DAGScheduler - Parents of final stage: List()
19:02:01.342 INFO  DAGScheduler - Missing parents: List()
19:02:01.342 INFO  DAGScheduler - Submitting ResultStage 33 (ParallelCollectionRDD[95] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:01.343 INFO  MemoryStore - Block broadcast_44 stored as values in memory (estimated size 3.0 KiB, free 1918.1 MiB)
19:02:01.345 INFO  MemoryStore - Block broadcast_44_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1918.1 MiB)
19:02:01.345 INFO  BlockManagerInfo - Added broadcast_44_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1919.7 MiB)
19:02:01.345 INFO  SparkContext - Created broadcast 44 from broadcast at DAGScheduler.scala:1580
19:02:01.345 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))
19:02:01.345 INFO  TaskSchedulerImpl - Adding task set 33.0 with 4 tasks resource profile 0
19:02:01.348 INFO  TaskSetManager - Starting task 0.0 in stage 33.0 (TID 77) (localhost, executor driver, partition 0, PROCESS_LOCAL, 169886 bytes) 
19:02:01.349 INFO  TaskSetManager - Starting task 1.0 in stage 33.0 (TID 78) (localhost, executor driver, partition 1, PROCESS_LOCAL, 170093 bytes) 
19:02:01.350 INFO  TaskSetManager - Starting task 2.0 in stage 33.0 (TID 79) (localhost, executor driver, partition 2, PROCESS_LOCAL, 170081 bytes) 
19:02:01.352 INFO  TaskSetManager - Starting task 3.0 in stage 33.0 (TID 80) (localhost, executor driver, partition 3, PROCESS_LOCAL, 169419 bytes) 
19:02:01.352 INFO  Executor - Running task 0.0 in stage 33.0 (TID 77)
19:02:01.352 INFO  Executor - Running task 1.0 in stage 33.0 (TID 78)
19:02:01.352 INFO  Executor - Running task 2.0 in stage 33.0 (TID 79)
19:02:01.354 INFO  Executor - Running task 3.0 in stage 33.0 (TID 80)
19:02:01.360 INFO  Executor - Finished task 1.0 in stage 33.0 (TID 78). 163411 bytes result sent to driver
19:02:01.360 INFO  Executor - Finished task 0.0 in stage 33.0 (TID 77). 163204 bytes result sent to driver
19:02:01.362 INFO  TaskSetManager - Finished task 1.0 in stage 33.0 (TID 78) in 14 ms on localhost (executor driver) (1/4)
19:02:01.364 INFO  TaskSetManager - Finished task 0.0 in stage 33.0 (TID 77) in 17 ms on localhost (executor driver) (2/4)
19:02:01.364 INFO  Executor - Finished task 2.0 in stage 33.0 (TID 79). 163399 bytes result sent to driver
19:02:01.365 INFO  Executor - Finished task 3.0 in stage 33.0 (TID 80). 162737 bytes result sent to driver
19:02:01.365 INFO  TaskSetManager - Finished task 2.0 in stage 33.0 (TID 79) in 16 ms on localhost (executor driver) (3/4)
19:02:01.367 INFO  TaskSetManager - Finished task 3.0 in stage 33.0 (TID 80) in 16 ms on localhost (executor driver) (4/4)
19:02:01.367 INFO  DAGScheduler - ResultStage 33 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.024 s
19:02:01.367 INFO  DAGScheduler - Job 24 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:01.367 INFO  TaskSchedulerImpl - Removed TaskSet 33.0, whose tasks have all completed, from pool 
19:02:01.367 INFO  TaskSchedulerImpl - Killing all running tasks in stage 33: Stage finished
19:02:01.367 INFO  DAGScheduler - Job 24 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.025972 s
19:02:01.370 INFO  FileInputFormat - Total input files to process : 1
19:02:01.411 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
19:02:01.411 INFO  DAGScheduler - Got job 25 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
19:02:01.411 INFO  DAGScheduler - Final stage: ResultStage 34 (collect at ReadsSparkSourceUnitTest.java:112)
19:02:01.411 INFO  DAGScheduler - Parents of final stage: List()
19:02:01.411 INFO  DAGScheduler - Missing parents: List()
19:02:01.412 INFO  DAGScheduler - Submitting ResultStage 34 (MapPartitionsRDD[102] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:01.433 INFO  MemoryStore - Block broadcast_45 stored as values in memory (estimated size 425.0 KiB, free 1917.7 MiB)
19:02:01.436 INFO  MemoryStore - Block broadcast_45_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1917.5 MiB)
19:02:01.436 INFO  BlockManagerInfo - Added broadcast_45_piece0 in memory on localhost:45255 (size: 152.7 KiB, free: 1919.5 MiB)
19:02:01.436 INFO  SparkContext - Created broadcast 45 from broadcast at DAGScheduler.scala:1580
19:02:01.436 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))
19:02:01.436 INFO  TaskSchedulerImpl - Adding task set 34.0 with 1 tasks resource profile 0
19:02:01.437 INFO  TaskSetManager - Starting task 0.0 in stage 34.0 (TID 81) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7905 bytes) 
19:02:01.438 INFO  Executor - Running task 0.0 in stage 34.0 (TID 81)
19:02:01.480 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
19:02:01.501 INFO  Executor - Finished task 0.0 in stage 34.0 (TID 81). 650184 bytes result sent to driver
19:02:01.504 INFO  TaskSetManager - Finished task 0.0 in stage 34.0 (TID 81) in 67 ms on localhost (executor driver) (1/1)
19:02:01.504 INFO  TaskSchedulerImpl - Removed TaskSet 34.0, whose tasks have all completed, from pool 
19:02:01.504 INFO  DAGScheduler - ResultStage 34 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.092 s
19:02:01.504 INFO  DAGScheduler - Job 25 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:01.504 INFO  TaskSchedulerImpl - Killing all running tasks in stage 34: Stage finished
19:02:01.505 INFO  DAGScheduler - Job 25 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.093778 s
19:02:01.511 INFO  MemoryStore - Block broadcast_46 stored as values in memory (estimated size 528.0 B, free 1917.5 MiB)
19:02:01.513 INFO  MemoryStore - Block broadcast_46_piece0 stored as bytes in memory (estimated size 183.0 B, free 1917.5 MiB)
19:02:01.513 INFO  BlockManagerInfo - Added broadcast_46_piece0 in memory on localhost:45255 (size: 183.0 B, free: 1919.5 MiB)
19:02:01.514 INFO  SparkContext - Created broadcast 46 from broadcast at CramSource.java:114
19:02:01.517 INFO  MemoryStore - Block broadcast_47 stored as values in memory (estimated size 297.2 KiB, free 1917.2 MiB)
19:02:01.525 INFO  MemoryStore - Block broadcast_47_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1917.2 MiB)
19:02:01.525 INFO  BlockManagerInfo - Added broadcast_47_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.5 MiB)
19:02:01.526 INFO  SparkContext - Created broadcast 47 from newAPIHadoopFile at PathSplitSource.java:96
19:02:01.553 INFO  MemoryStore - Block broadcast_48 stored as values in memory (estimated size 528.0 B, free 1917.2 MiB)
19:02:01.554 INFO  MemoryStore - Block broadcast_48_piece0 stored as bytes in memory (estimated size 183.0 B, free 1917.2 MiB)
19:02:01.554 INFO  BlockManagerInfo - Added broadcast_48_piece0 in memory on localhost:45255 (size: 183.0 B, free: 1919.5 MiB)
19:02:01.555 INFO  SparkContext - Created broadcast 48 from broadcast at CramSource.java:114
19:02:01.557 INFO  MemoryStore - Block broadcast_49 stored as values in memory (estimated size 297.2 KiB, free 1916.9 MiB)
19:02:01.564 INFO  MemoryStore - Block broadcast_49_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1916.8 MiB)
19:02:01.564 INFO  BlockManagerInfo - Added broadcast_49_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.4 MiB)
19:02:01.564 INFO  SparkContext - Created broadcast 49 from newAPIHadoopFile at PathSplitSource.java:96
19:02:01.584 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
19:02:01.584 INFO  DAGScheduler - Got job 26 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
19:02:01.584 INFO  DAGScheduler - Final stage: ResultStage 35 (collect at ReadsSparkSourceUnitTest.java:111)
19:02:01.584 INFO  DAGScheduler - Parents of final stage: List()
19:02:01.584 INFO  DAGScheduler - Missing parents: List()
19:02:01.585 INFO  DAGScheduler - Submitting ResultStage 35 (ParallelCollectionRDD[107] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:01.586 INFO  MemoryStore - Block broadcast_50 stored as values in memory (estimated size 3.0 KiB, free 1916.8 MiB)
19:02:01.587 INFO  MemoryStore - Block broadcast_50_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1916.8 MiB)
19:02:01.587 INFO  BlockManagerInfo - Added broadcast_50_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1919.4 MiB)
19:02:01.587 INFO  SparkContext - Created broadcast 50 from broadcast at DAGScheduler.scala:1580
19:02:01.588 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))
19:02:01.588 INFO  TaskSchedulerImpl - Adding task set 35.0 with 4 tasks resource profile 0
19:02:01.592 INFO  TaskSetManager - Starting task 0.0 in stage 35.0 (TID 82) (localhost, executor driver, partition 0, PROCESS_LOCAL, 45675 bytes) 
19:02:01.593 INFO  TaskSetManager - Starting task 1.0 in stage 35.0 (TID 83) (localhost, executor driver, partition 1, PROCESS_LOCAL, 45855 bytes) 
19:02:01.594 INFO  TaskSetManager - Starting task 2.0 in stage 35.0 (TID 84) (localhost, executor driver, partition 2, PROCESS_LOCAL, 45795 bytes) 
19:02:01.595 INFO  TaskSetManager - Starting task 3.0 in stage 35.0 (TID 85) (localhost, executor driver, partition 3, PROCESS_LOCAL, 46068 bytes) 
19:02:01.596 INFO  Executor - Running task 0.0 in stage 35.0 (TID 82)
19:02:01.596 INFO  Executor - Running task 1.0 in stage 35.0 (TID 83)
19:02:01.596 INFO  Executor - Running task 3.0 in stage 35.0 (TID 85)
19:02:01.596 INFO  Executor - Running task 2.0 in stage 35.0 (TID 84)
19:02:01.599 INFO  Executor - Finished task 3.0 in stage 35.0 (TID 85). 39343 bytes result sent to driver
19:02:01.600 INFO  Executor - Finished task 0.0 in stage 35.0 (TID 82). 38950 bytes result sent to driver
19:02:01.601 INFO  TaskSetManager - Finished task 3.0 in stage 35.0 (TID 85) in 6 ms on localhost (executor driver) (1/4)
19:02:01.601 INFO  Executor - Finished task 2.0 in stage 35.0 (TID 84). 39113 bytes result sent to driver
19:02:01.601 INFO  Executor - Finished task 1.0 in stage 35.0 (TID 83). 39173 bytes result sent to driver
19:02:01.602 INFO  TaskSetManager - Finished task 2.0 in stage 35.0 (TID 84) in 8 ms on localhost (executor driver) (2/4)
19:02:01.602 INFO  TaskSetManager - Finished task 0.0 in stage 35.0 (TID 82) in 14 ms on localhost (executor driver) (3/4)
19:02:01.602 INFO  TaskSetManager - Finished task 1.0 in stage 35.0 (TID 83) in 10 ms on localhost (executor driver) (4/4)
19:02:01.602 INFO  TaskSchedulerImpl - Removed TaskSet 35.0, whose tasks have all completed, from pool 
19:02:01.603 INFO  DAGScheduler - ResultStage 35 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.018 s
19:02:01.603 INFO  DAGScheduler - Job 26 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:01.603 INFO  TaskSchedulerImpl - Killing all running tasks in stage 35: Stage finished
19:02:01.603 INFO  DAGScheduler - Job 26 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.019502 s
19:02:01.605 INFO  FileInputFormat - Total input files to process : 1
19:02:01.637 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
19:02:01.638 INFO  DAGScheduler - Got job 27 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
19:02:01.638 INFO  DAGScheduler - Final stage: ResultStage 36 (collect at ReadsSparkSourceUnitTest.java:112)
19:02:01.638 INFO  DAGScheduler - Parents of final stage: List()
19:02:01.638 INFO  DAGScheduler - Missing parents: List()
19:02:01.638 INFO  DAGScheduler - Submitting ResultStage 36 (MapPartitionsRDD[113] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:01.656 INFO  MemoryStore - Block broadcast_51 stored as values in memory (estimated size 286.0 KiB, free 1916.5 MiB)
19:02:01.658 INFO  MemoryStore - Block broadcast_51_piece0 stored as bytes in memory (estimated size 103.1 KiB, free 1916.4 MiB)
19:02:01.658 INFO  BlockManagerInfo - Added broadcast_51_piece0 in memory on localhost:45255 (size: 103.1 KiB, free: 1919.3 MiB)
19:02:01.659 INFO  SparkContext - Created broadcast 51 from broadcast at DAGScheduler.scala:1580
19:02:01.659 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))
19:02:01.659 INFO  TaskSchedulerImpl - Adding task set 36.0 with 1 tasks resource profile 0
19:02:01.660 INFO  TaskSetManager - Starting task 0.0 in stage 36.0 (TID 86) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7832 bytes) 
19:02:01.660 INFO  Executor - Running task 0.0 in stage 36.0 (TID 86)
19:02:01.689 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram:0+50619
19:02:01.703 INFO  Executor - Finished task 0.0 in stage 36.0 (TID 86). 154101 bytes result sent to driver
19:02:01.705 INFO  TaskSetManager - Finished task 0.0 in stage 36.0 (TID 86) in 45 ms on localhost (executor driver) (1/1)
19:02:01.705 INFO  TaskSchedulerImpl - Removed TaskSet 36.0, whose tasks have all completed, from pool 
19:02:01.705 INFO  DAGScheduler - ResultStage 36 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.066 s
19:02:01.705 INFO  DAGScheduler - Job 27 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:01.705 INFO  TaskSchedulerImpl - Killing all running tasks in stage 36: Stage finished
19:02:01.705 INFO  DAGScheduler - Job 27 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.068087 s
19:02:01.712 INFO  MemoryStore - Block broadcast_52 stored as values in memory (estimated size 600.0 B, free 1916.4 MiB)
19:02:01.713 INFO  MemoryStore - Block broadcast_52_piece0 stored as bytes in memory (estimated size 202.0 B, free 1916.4 MiB)
19:02:01.713 INFO  BlockManagerInfo - Added broadcast_52_piece0 in memory on localhost:45255 (size: 202.0 B, free: 1919.3 MiB)
19:02:01.714 INFO  SparkContext - Created broadcast 52 from broadcast at CramSource.java:114
19:02:01.717 INFO  MemoryStore - Block broadcast_53 stored as values in memory (estimated size 297.3 KiB, free 1916.2 MiB)
19:02:01.728 INFO  MemoryStore - Block broadcast_53_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1916.1 MiB)
19:02:01.728 INFO  BlockManagerInfo - Added broadcast_53_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.3 MiB)
19:02:01.729 INFO  SparkContext - Created broadcast 53 from newAPIHadoopFile at PathSplitSource.java:96
19:02:01.751 INFO  MemoryStore - Block broadcast_54 stored as values in memory (estimated size 600.0 B, free 1916.1 MiB)
19:02:01.752 INFO  MemoryStore - Block broadcast_54_piece0 stored as bytes in memory (estimated size 202.0 B, free 1916.1 MiB)
19:02:01.753 INFO  BlockManagerInfo - Added broadcast_54_piece0 in memory on localhost:45255 (size: 202.0 B, free: 1919.3 MiB)
19:02:01.753 INFO  SparkContext - Created broadcast 54 from broadcast at CramSource.java:114
19:02:01.755 INFO  MemoryStore - Block broadcast_55 stored as values in memory (estimated size 297.3 KiB, free 1915.8 MiB)
19:02:01.762 INFO  MemoryStore - Block broadcast_55_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1915.8 MiB)
19:02:01.762 INFO  BlockManagerInfo - Added broadcast_55_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.2 MiB)
19:02:01.762 INFO  SparkContext - Created broadcast 55 from newAPIHadoopFile at PathSplitSource.java:96
19:02:01.781 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
19:02:01.782 INFO  DAGScheduler - Got job 28 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
19:02:01.782 INFO  DAGScheduler - Final stage: ResultStage 37 (collect at ReadsSparkSourceUnitTest.java:111)
19:02:01.782 INFO  DAGScheduler - Parents of final stage: List()
19:02:01.782 INFO  DAGScheduler - Missing parents: List()
19:02:01.782 INFO  DAGScheduler - Submitting ResultStage 37 (ParallelCollectionRDD[118] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:01.783 INFO  MemoryStore - Block broadcast_56 stored as values in memory (estimated size 3.0 KiB, free 1915.8 MiB)
19:02:01.784 INFO  MemoryStore - Block broadcast_56_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1915.8 MiB)
19:02:01.784 INFO  BlockManagerInfo - Added broadcast_56_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1919.2 MiB)
19:02:01.784 INFO  SparkContext - Created broadcast 56 from broadcast at DAGScheduler.scala:1580
19:02:01.784 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))
19:02:01.784 INFO  TaskSchedulerImpl - Adding task set 37.0 with 4 tasks resource profile 0
19:02:01.785 INFO  TaskSetManager - Starting task 0.0 in stage 37.0 (TID 87) (localhost, executor driver, partition 0, PROCESS_LOCAL, 8303 bytes) 
19:02:01.786 INFO  TaskSetManager - Starting task 1.0 in stage 37.0 (TID 88) (localhost, executor driver, partition 1, PROCESS_LOCAL, 8292 bytes) 
19:02:01.786 INFO  TaskSetManager - Starting task 2.0 in stage 37.0 (TID 89) (localhost, executor driver, partition 2, PROCESS_LOCAL, 8292 bytes) 
19:02:01.786 INFO  TaskSetManager - Starting task 3.0 in stage 37.0 (TID 90) (localhost, executor driver, partition 3, PROCESS_LOCAL, 8184 bytes) 
19:02:01.787 INFO  Executor - Running task 0.0 in stage 37.0 (TID 87)
19:02:01.787 INFO  Executor - Running task 2.0 in stage 37.0 (TID 89)
19:02:01.787 INFO  Executor - Running task 1.0 in stage 37.0 (TID 88)
19:02:01.787 INFO  Executor - Running task 3.0 in stage 37.0 (TID 90)
19:02:01.790 INFO  Executor - Finished task 2.0 in stage 37.0 (TID 89). 1610 bytes result sent to driver
19:02:01.790 INFO  Executor - Finished task 0.0 in stage 37.0 (TID 87). 1621 bytes result sent to driver
19:02:01.790 INFO  Executor - Finished task 1.0 in stage 37.0 (TID 88). 1567 bytes result sent to driver
19:02:01.791 INFO  TaskSetManager - Finished task 2.0 in stage 37.0 (TID 89) in 5 ms on localhost (executor driver) (1/4)
19:02:01.791 INFO  TaskSetManager - Finished task 0.0 in stage 37.0 (TID 87) in 6 ms on localhost (executor driver) (2/4)
19:02:01.791 INFO  TaskSetManager - Finished task 1.0 in stage 37.0 (TID 88) in 6 ms on localhost (executor driver) (3/4)
19:02:01.791 INFO  Executor - Finished task 3.0 in stage 37.0 (TID 90). 1502 bytes result sent to driver
19:02:01.792 INFO  TaskSetManager - Finished task 3.0 in stage 37.0 (TID 90) in 6 ms on localhost (executor driver) (4/4)
19:02:01.792 INFO  TaskSchedulerImpl - Removed TaskSet 37.0, whose tasks have all completed, from pool 
19:02:01.793 INFO  DAGScheduler - ResultStage 37 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.010 s
19:02:01.793 INFO  DAGScheduler - Job 28 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:01.793 INFO  TaskSchedulerImpl - Killing all running tasks in stage 37: Stage finished
19:02:01.793 INFO  DAGScheduler - Job 28 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.011642 s
19:02:01.795 INFO  FileInputFormat - Total input files to process : 1
19:02:01.823 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
19:02:01.823 INFO  DAGScheduler - Got job 29 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
19:02:01.823 INFO  DAGScheduler - Final stage: ResultStage 38 (collect at ReadsSparkSourceUnitTest.java:112)
19:02:01.823 INFO  DAGScheduler - Parents of final stage: List()
19:02:01.824 INFO  DAGScheduler - Missing parents: List()
19:02:01.824 INFO  DAGScheduler - Submitting ResultStage 38 (MapPartitionsRDD[124] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:01.837 INFO  MemoryStore - Block broadcast_57 stored as values in memory (estimated size 286.0 KiB, free 1915.5 MiB)
19:02:01.839 INFO  MemoryStore - Block broadcast_57_piece0 stored as bytes in memory (estimated size 103.1 KiB, free 1915.4 MiB)
19:02:01.839 INFO  BlockManagerInfo - Added broadcast_57_piece0 in memory on localhost:45255 (size: 103.1 KiB, free: 1919.1 MiB)
19:02:01.839 INFO  SparkContext - Created broadcast 57 from broadcast at DAGScheduler.scala:1580
19:02:01.840 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))
19:02:01.840 INFO  TaskSchedulerImpl - Adding task set 38.0 with 1 tasks resource profile 0
19:02:01.841 INFO  TaskSetManager - Starting task 0.0 in stage 38.0 (TID 91) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7844 bytes) 
19:02:01.841 INFO  Executor - Running task 0.0 in stage 38.0 (TID 91)
19:02:01.872 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/valid.cram:0+13330
19:02:01.878 INFO  Executor - Finished task 0.0 in stage 38.0 (TID 91). 3736 bytes result sent to driver
19:02:01.879 INFO  TaskSetManager - Finished task 0.0 in stage 38.0 (TID 91) in 39 ms on localhost (executor driver) (1/1)
19:02:01.879 INFO  DAGScheduler - ResultStage 38 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.055 s
19:02:01.880 INFO  DAGScheduler - Job 29 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:01.880 INFO  TaskSchedulerImpl - Removed TaskSet 38.0, whose tasks have all completed, from pool 
19:02:01.880 INFO  TaskSchedulerImpl - Killing all running tasks in stage 38: Stage finished
19:02:01.880 INFO  DAGScheduler - Job 29 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.057136 s
19:02:01.887 INFO  MemoryStore - Block broadcast_58 stored as values in memory (estimated size 297.2 KiB, free 1915.1 MiB)
19:02:01.894 INFO  MemoryStore - Block broadcast_58_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1915.0 MiB)
19:02:01.894 INFO  BlockManagerInfo - Added broadcast_58_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.1 MiB)
19:02:01.894 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
19:02:01.927 INFO  MemoryStore - Block broadcast_59 stored as values in memory (estimated size 297.2 KiB, free 1914.7 MiB)
19:02:01.935 INFO  MemoryStore - Block broadcast_59_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1914.7 MiB)
19:02:01.935 INFO  BlockManagerInfo - Added broadcast_59_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.0 MiB)
19:02:01.936 INFO  SparkContext - Created broadcast 59 from newAPIHadoopFile at PathSplitSource.java:96
19:02:01.962 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
19:02:01.963 INFO  DAGScheduler - Got job 30 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
19:02:01.963 INFO  DAGScheduler - Final stage: ResultStage 39 (collect at ReadsSparkSourceUnitTest.java:111)
19:02:01.963 INFO  DAGScheduler - Parents of final stage: List()
19:02:01.963 INFO  DAGScheduler - Missing parents: List()
19:02:01.963 INFO  DAGScheduler - Submitting ResultStage 39 (ParallelCollectionRDD[130] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:01.964 INFO  MemoryStore - Block broadcast_60 stored as values in memory (estimated size 3.0 KiB, free 1914.7 MiB)
19:02:01.965 INFO  MemoryStore - Block broadcast_60_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1914.7 MiB)
19:02:01.966 INFO  BlockManagerInfo - Added broadcast_60_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1919.0 MiB)
19:02:01.966 INFO  SparkContext - Created broadcast 60 from broadcast at DAGScheduler.scala:1580
19:02:01.966 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))
19:02:01.966 INFO  TaskSchedulerImpl - Adding task set 39.0 with 4 tasks resource profile 0
19:02:01.968 INFO  TaskSetManager - Starting task 0.0 in stage 39.0 (TID 92) (localhost, executor driver, partition 0, PROCESS_LOCAL, 47080 bytes) 
19:02:01.968 INFO  TaskSetManager - Starting task 1.0 in stage 39.0 (TID 93) (localhost, executor driver, partition 1, PROCESS_LOCAL, 47194 bytes) 
19:02:01.969 INFO  TaskSetManager - Starting task 2.0 in stage 39.0 (TID 94) (localhost, executor driver, partition 2, PROCESS_LOCAL, 47105 bytes) 
19:02:01.969 INFO  TaskSetManager - Starting task 3.0 in stage 39.0 (TID 95) (localhost, executor driver, partition 3, PROCESS_LOCAL, 47530 bytes) 
19:02:01.970 INFO  Executor - Running task 1.0 in stage 39.0 (TID 93)
19:02:01.970 INFO  Executor - Running task 0.0 in stage 39.0 (TID 92)
19:02:01.972 INFO  Executor - Running task 3.0 in stage 39.0 (TID 95)
19:02:01.972 INFO  Executor - Running task 2.0 in stage 39.0 (TID 94)
19:02:01.974 INFO  Executor - Finished task 3.0 in stage 39.0 (TID 95). 40762 bytes result sent to driver
19:02:01.976 INFO  Executor - Finished task 2.0 in stage 39.0 (TID 94). 40380 bytes result sent to driver
19:02:01.976 INFO  Executor - Finished task 1.0 in stage 39.0 (TID 93). 40469 bytes result sent to driver
19:02:01.974 INFO  Executor - Finished task 0.0 in stage 39.0 (TID 92). 40355 bytes result sent to driver
19:02:01.977 INFO  TaskSetManager - Finished task 1.0 in stage 39.0 (TID 93) in 9 ms on localhost (executor driver) (1/4)
19:02:01.977 INFO  TaskSetManager - Finished task 3.0 in stage 39.0 (TID 95) in 8 ms on localhost (executor driver) (2/4)
19:02:01.977 INFO  TaskSetManager - Finished task 0.0 in stage 39.0 (TID 92) in 10 ms on localhost (executor driver) (3/4)
19:02:01.979 INFO  TaskSetManager - Finished task 2.0 in stage 39.0 (TID 94) in 11 ms on localhost (executor driver) (4/4)
19:02:01.979 INFO  TaskSchedulerImpl - Removed TaskSet 39.0, whose tasks have all completed, from pool 
19:02:01.979 INFO  DAGScheduler - ResultStage 39 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.016 s
19:02:01.980 INFO  DAGScheduler - Job 30 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:01.980 INFO  TaskSchedulerImpl - Killing all running tasks in stage 39: Stage finished
19:02:01.980 INFO  DAGScheduler - Job 30 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.017974 s
19:02:01.982 INFO  FileInputFormat - Total input files to process : 1
19:02:02.044 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
19:02:02.045 INFO  DAGScheduler - Got job 31 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
19:02:02.045 INFO  DAGScheduler - Final stage: ResultStage 40 (collect at ReadsSparkSourceUnitTest.java:112)
19:02:02.045 INFO  DAGScheduler - Parents of final stage: List()
19:02:02.045 INFO  DAGScheduler - Missing parents: List()
19:02:02.046 INFO  DAGScheduler - Submitting ResultStage 40 (MapPartitionsRDD[137] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:02.078 INFO  MemoryStore - Block broadcast_61 stored as values in memory (estimated size 425.0 KiB, free 1914.3 MiB)
19:02:02.080 INFO  MemoryStore - Block broadcast_61_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1914.1 MiB)
19:02:02.080 INFO  BlockManagerInfo - Added broadcast_61_piece0 in memory on localhost:45255 (size: 152.7 KiB, free: 1918.9 MiB)
19:02:02.081 INFO  SparkContext - Created broadcast 61 from broadcast at DAGScheduler.scala:1580
19:02:02.081 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))
19:02:02.081 INFO  TaskSchedulerImpl - Adding task set 40.0 with 1 tasks resource profile 0
19:02:02.082 INFO  TaskSetManager - Starting task 0.0 in stage 40.0 (TID 96) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7831 bytes) 
19:02:02.083 INFO  Executor - Running task 0.0 in stage 40.0 (TID 96)
19:02:02.144 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
19:02:02.155 INFO  Executor - Finished task 0.0 in stage 40.0 (TID 96). 159615 bytes result sent to driver
19:02:02.157 INFO  TaskSetManager - Finished task 0.0 in stage 40.0 (TID 96) in 75 ms on localhost (executor driver) (1/1)
19:02:02.157 INFO  TaskSchedulerImpl - Removed TaskSet 40.0, whose tasks have all completed, from pool 
19:02:02.157 INFO  DAGScheduler - ResultStage 40 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.111 s
19:02:02.157 INFO  DAGScheduler - Job 31 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:02.157 INFO  TaskSchedulerImpl - Killing all running tasks in stage 40: Stage finished
19:02:02.157 INFO  DAGScheduler - Job 31 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.112788 s
19:02:02.163 INFO  MemoryStore - Block broadcast_62 stored as values in memory (estimated size 528.0 B, free 1914.1 MiB)
19:02:02.163 INFO  MemoryStore - Block broadcast_62_piece0 stored as bytes in memory (estimated size 183.0 B, free 1914.1 MiB)
19:02:02.164 INFO  BlockManagerInfo - Added broadcast_62_piece0 in memory on localhost:45255 (size: 183.0 B, free: 1918.9 MiB)
19:02:02.164 INFO  SparkContext - Created broadcast 62 from broadcast at CramSource.java:114
19:02:02.168 INFO  MemoryStore - Block broadcast_63 stored as values in memory (estimated size 297.2 KiB, free 1913.8 MiB)
19:02:02.178 INFO  MemoryStore - Block broadcast_63_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1913.8 MiB)
19:02:02.179 INFO  BlockManagerInfo - Added broadcast_63_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1918.8 MiB)
19:02:02.179 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
19:02:02.218 INFO  MemoryStore - Block broadcast_64 stored as values in memory (estimated size 528.0 B, free 1913.8 MiB)
19:02:02.219 INFO  MemoryStore - Block broadcast_64_piece0 stored as bytes in memory (estimated size 183.0 B, free 1913.8 MiB)
19:02:02.219 INFO  BlockManagerInfo - Added broadcast_64_piece0 in memory on localhost:45255 (size: 183.0 B, free: 1918.8 MiB)
19:02:02.220 INFO  SparkContext - Created broadcast 64 from broadcast at CramSource.java:114
19:02:02.223 INFO  MemoryStore - Block broadcast_65 stored as values in memory (estimated size 297.2 KiB, free 1913.5 MiB)
19:02:02.233 INFO  MemoryStore - Block broadcast_65_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1913.5 MiB)
19:02:02.234 INFO  BlockManagerInfo - Added broadcast_65_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1918.8 MiB)
19:02:02.235 INFO  SparkContext - Created broadcast 65 from newAPIHadoopFile at PathSplitSource.java:96
19:02:02.264 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
19:02:02.265 INFO  DAGScheduler - Got job 32 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
19:02:02.265 INFO  DAGScheduler - Final stage: ResultStage 41 (collect at ReadsSparkSourceUnitTest.java:111)
19:02:02.265 INFO  DAGScheduler - Parents of final stage: List()
19:02:02.265 INFO  DAGScheduler - Missing parents: List()
19:02:02.265 INFO  DAGScheduler - Submitting ResultStage 41 (ParallelCollectionRDD[142] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:02.267 INFO  MemoryStore - Block broadcast_66 stored as values in memory (estimated size 3.0 KiB, free 1913.4 MiB)
19:02:02.268 INFO  MemoryStore - Block broadcast_66_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1913.4 MiB)
19:02:02.268 INFO  BlockManagerInfo - Added broadcast_66_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1918.8 MiB)
19:02:02.268 INFO  SparkContext - Created broadcast 66 from broadcast at DAGScheduler.scala:1580
19:02:02.268 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))
19:02:02.268 INFO  TaskSchedulerImpl - Adding task set 41.0 with 4 tasks resource profile 0
19:02:02.271 INFO  TaskSetManager - Starting task 0.0 in stage 41.0 (TID 97) (localhost, executor driver, partition 0, PROCESS_LOCAL, 45675 bytes) 
19:02:02.272 INFO  TaskSetManager - Starting task 1.0 in stage 41.0 (TID 98) (localhost, executor driver, partition 1, PROCESS_LOCAL, 45855 bytes) 
19:02:02.273 INFO  TaskSetManager - Starting task 2.0 in stage 41.0 (TID 99) (localhost, executor driver, partition 2, PROCESS_LOCAL, 45795 bytes) 
19:02:02.275 INFO  TaskSetManager - Starting task 3.0 in stage 41.0 (TID 100) (localhost, executor driver, partition 3, PROCESS_LOCAL, 46068 bytes) 
19:02:02.275 INFO  Executor - Running task 1.0 in stage 41.0 (TID 98)
19:02:02.275 INFO  Executor - Running task 0.0 in stage 41.0 (TID 97)
19:02:02.277 INFO  Executor - Running task 3.0 in stage 41.0 (TID 100)
19:02:02.278 INFO  Executor - Finished task 0.0 in stage 41.0 (TID 97). 38950 bytes result sent to driver
19:02:02.279 INFO  Executor - Running task 2.0 in stage 41.0 (TID 99)
19:02:02.281 INFO  Executor - Finished task 1.0 in stage 41.0 (TID 98). 39130 bytes result sent to driver
19:02:02.279 INFO  Executor - Finished task 3.0 in stage 41.0 (TID 100). 39300 bytes result sent to driver
19:02:02.281 INFO  Executor - Finished task 2.0 in stage 41.0 (TID 99). 39070 bytes result sent to driver
19:02:02.283 INFO  TaskSetManager - Finished task 0.0 in stage 41.0 (TID 97) in 13 ms on localhost (executor driver) (1/4)
19:02:02.283 INFO  TaskSetManager - Finished task 3.0 in stage 41.0 (TID 100) in 9 ms on localhost (executor driver) (2/4)
19:02:02.283 INFO  TaskSetManager - Finished task 1.0 in stage 41.0 (TID 98) in 12 ms on localhost (executor driver) (3/4)
19:02:02.284 INFO  TaskSetManager - Finished task 2.0 in stage 41.0 (TID 99) in 12 ms on localhost (executor driver) (4/4)
19:02:02.284 INFO  TaskSchedulerImpl - Removed TaskSet 41.0, whose tasks have all completed, from pool 
19:02:02.285 INFO  DAGScheduler - ResultStage 41 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.019 s
19:02:02.285 INFO  DAGScheduler - Job 32 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:02.285 INFO  TaskSchedulerImpl - Killing all running tasks in stage 41: Stage finished
19:02:02.285 INFO  DAGScheduler - Job 32 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.020888 s
19:02:02.287 INFO  FileInputFormat - Total input files to process : 1
19:02:02.327 INFO  BlockManagerInfo - Removed broadcast_47_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1918.8 MiB)
19:02:02.329 INFO  BlockManagerInfo - Removed broadcast_53_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1918.9 MiB)
19:02:02.332 INFO  BlockManagerInfo - Removed broadcast_54_piece0 on localhost:45255 in memory (size: 202.0 B, free: 1918.9 MiB)
19:02:02.334 INFO  BlockManagerInfo - Removed broadcast_48_piece0 on localhost:45255 in memory (size: 183.0 B, free: 1918.9 MiB)
19:02:02.335 INFO  BlockManagerInfo - Removed broadcast_51_piece0 on localhost:45255 in memory (size: 103.1 KiB, free: 1919.0 MiB)
19:02:02.337 INFO  BlockManagerInfo - Removed broadcast_50_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.0 MiB)
19:02:02.338 INFO  BlockManagerInfo - Removed broadcast_55_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.0 MiB)
19:02:02.339 INFO  BlockManagerInfo - Removed broadcast_58_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.1 MiB)
19:02:02.340 INFO  BlockManagerInfo - Removed broadcast_52_piece0 on localhost:45255 in memory (size: 202.0 B, free: 1919.1 MiB)
19:02:02.342 INFO  BlockManagerInfo - Removed broadcast_38_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.1 MiB)
19:02:02.344 INFO  BlockManagerInfo - Removed broadcast_61_piece0 on localhost:45255 in memory (size: 152.7 KiB, free: 1919.2 MiB)
19:02:02.346 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
19:02:02.346 INFO  BlockManagerInfo - Removed broadcast_49_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.3 MiB)
19:02:02.347 INFO  DAGScheduler - Got job 33 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
19:02:02.347 INFO  DAGScheduler - Final stage: ResultStage 42 (collect at ReadsSparkSourceUnitTest.java:112)
19:02:02.347 INFO  DAGScheduler - Parents of final stage: List()
19:02:02.347 INFO  DAGScheduler - Missing parents: List()
19:02:02.348 INFO  DAGScheduler - Submitting ResultStage 42 (MapPartitionsRDD[148] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:02.350 INFO  BlockManagerInfo - Removed broadcast_40_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.3 MiB)
19:02:02.352 INFO  BlockManagerInfo - Removed broadcast_45_piece0 on localhost:45255 in memory (size: 152.7 KiB, free: 1919.4 MiB)
19:02:02.353 INFO  BlockManagerInfo - Removed broadcast_46_piece0 on localhost:45255 in memory (size: 183.0 B, free: 1919.4 MiB)
19:02:02.354 INFO  BlockManagerInfo - Removed broadcast_41_piece0 on localhost:45255 in memory (size: 152.7 KiB, free: 1919.6 MiB)
19:02:02.355 INFO  BlockManagerInfo - Removed broadcast_60_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.6 MiB)
19:02:02.358 INFO  BlockManagerInfo - Removed broadcast_63_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.6 MiB)
19:02:02.361 INFO  BlockManagerInfo - Removed broadcast_62_piece0 on localhost:45255 in memory (size: 183.0 B, free: 1919.6 MiB)
19:02:02.361 INFO  BlockManagerInfo - Removed broadcast_44_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.7 MiB)
19:02:02.362 INFO  BlockManagerInfo - Removed broadcast_56_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.7 MiB)
19:02:02.364 INFO  BlockManagerInfo - Removed broadcast_57_piece0 on localhost:45255 in memory (size: 103.1 KiB, free: 1919.8 MiB)
19:02:02.369 INFO  BlockManagerInfo - Removed broadcast_43_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.8 MiB)
19:02:02.370 INFO  BlockManagerInfo - Removed broadcast_42_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.9 MiB)
19:02:02.371 INFO  BlockManagerInfo - Removed broadcast_66_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.9 MiB)
19:02:02.371 INFO  MemoryStore - Block broadcast_67 stored as values in memory (estimated size 286.0 KiB, free 1918.7 MiB)
19:02:02.372 INFO  MemoryStore - Block broadcast_67_piece0 stored as bytes in memory (estimated size 103.1 KiB, free 1918.6 MiB)
19:02:02.373 INFO  BlockManagerInfo - Added broadcast_67_piece0 in memory on localhost:45255 (size: 103.1 KiB, free: 1919.8 MiB)
19:02:02.373 INFO  BlockManagerInfo - Removed broadcast_39_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.8 MiB)
19:02:02.373 INFO  SparkContext - Created broadcast 67 from broadcast at DAGScheduler.scala:1580
19:02:02.373 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))
19:02:02.374 INFO  TaskSchedulerImpl - Adding task set 42.0 with 1 tasks resource profile 0
19:02:02.375 INFO  TaskSetManager - Starting task 0.0 in stage 42.0 (TID 101) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7832 bytes) 
19:02:02.375 INFO  BlockManagerInfo - Removed broadcast_59_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.9 MiB)
19:02:02.375 INFO  Executor - Running task 0.0 in stage 42.0 (TID 101)
19:02:02.414 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
19:02:02.430 INFO  Executor - Finished task 0.0 in stage 42.0 (TID 101). 154101 bytes result sent to driver
19:02:02.434 INFO  TaskSetManager - Finished task 0.0 in stage 42.0 (TID 101) in 60 ms on localhost (executor driver) (1/1)
19:02:02.434 INFO  TaskSchedulerImpl - Removed TaskSet 42.0, whose tasks have all completed, from pool 
19:02:02.437 INFO  DAGScheduler - ResultStage 42 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.089 s
19:02:02.437 INFO  DAGScheduler - Job 33 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:02.437 INFO  TaskSchedulerImpl - Killing all running tasks in stage 42: Stage finished
19:02:02.437 INFO  DAGScheduler - Job 33 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.090993 s
19:02:02.444 INFO  MemoryStore - Block broadcast_68 stored as values in memory (estimated size 297.2 KiB, free 1919.0 MiB)
19:02:02.452 INFO  MemoryStore - Block broadcast_68_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1918.9 MiB)
19:02:02.453 INFO  BlockManagerInfo - Added broadcast_68_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.8 MiB)
19:02:02.453 INFO  SparkContext - Created broadcast 68 from newAPIHadoopFile at PathSplitSource.java:96
19:02:02.483 INFO  MemoryStore - Block broadcast_69 stored as values in memory (estimated size 297.2 KiB, free 1918.7 MiB)
19:02:02.490 INFO  MemoryStore - Block broadcast_69_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1918.6 MiB)
19:02:02.490 INFO  BlockManagerInfo - Added broadcast_69_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.8 MiB)
19:02:02.491 INFO  SparkContext - Created broadcast 69 from newAPIHadoopFile at PathSplitSource.java:96
19:02:02.519 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
19:02:02.519 INFO  DAGScheduler - Got job 34 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
19:02:02.519 INFO  DAGScheduler - Final stage: ResultStage 43 (collect at ReadsSparkSourceUnitTest.java:111)
19:02:02.519 INFO  DAGScheduler - Parents of final stage: List()
19:02:02.519 INFO  DAGScheduler - Missing parents: List()
19:02:02.520 INFO  DAGScheduler - Submitting ResultStage 43 (ParallelCollectionRDD[154] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:02.521 INFO  MemoryStore - Block broadcast_70 stored as values in memory (estimated size 3.0 KiB, free 1918.6 MiB)
19:02:02.521 INFO  MemoryStore - Block broadcast_70_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1918.6 MiB)
19:02:02.522 INFO  BlockManagerInfo - Added broadcast_70_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1919.8 MiB)
19:02:02.522 INFO  SparkContext - Created broadcast 70 from broadcast at DAGScheduler.scala:1580
19:02:02.523 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))
19:02:02.523 INFO  TaskSchedulerImpl - Adding task set 43.0 with 4 tasks resource profile 0
19:02:02.524 INFO  TaskSetManager - Starting task 0.0 in stage 43.0 (TID 102) (localhost, executor driver, partition 0, PROCESS_LOCAL, 47080 bytes) 
19:02:02.524 INFO  TaskSetManager - Starting task 1.0 in stage 43.0 (TID 103) (localhost, executor driver, partition 1, PROCESS_LOCAL, 47194 bytes) 
19:02:02.525 INFO  TaskSetManager - Starting task 2.0 in stage 43.0 (TID 104) (localhost, executor driver, partition 2, PROCESS_LOCAL, 47105 bytes) 
19:02:02.526 INFO  TaskSetManager - Starting task 3.0 in stage 43.0 (TID 105) (localhost, executor driver, partition 3, PROCESS_LOCAL, 47530 bytes) 
19:02:02.526 INFO  Executor - Running task 1.0 in stage 43.0 (TID 103)
19:02:02.526 INFO  Executor - Running task 2.0 in stage 43.0 (TID 104)
19:02:02.526 INFO  Executor - Running task 0.0 in stage 43.0 (TID 102)
19:02:02.529 INFO  Executor - Finished task 1.0 in stage 43.0 (TID 103). 40469 bytes result sent to driver
19:02:02.529 INFO  Executor - Finished task 2.0 in stage 43.0 (TID 104). 40380 bytes result sent to driver
19:02:02.529 INFO  Executor - Running task 3.0 in stage 43.0 (TID 105)
19:02:02.531 INFO  Executor - Finished task 3.0 in stage 43.0 (TID 105). 40762 bytes result sent to driver
19:02:02.531 INFO  Executor - Finished task 0.0 in stage 43.0 (TID 102). 40355 bytes result sent to driver
19:02:02.532 INFO  TaskSetManager - Finished task 1.0 in stage 43.0 (TID 103) in 8 ms on localhost (executor driver) (1/4)
19:02:02.533 INFO  TaskSetManager - Finished task 3.0 in stage 43.0 (TID 105) in 8 ms on localhost (executor driver) (2/4)
19:02:02.533 INFO  TaskSetManager - Finished task 0.0 in stage 43.0 (TID 102) in 9 ms on localhost (executor driver) (3/4)
19:02:02.534 INFO  TaskSetManager - Finished task 2.0 in stage 43.0 (TID 104) in 9 ms on localhost (executor driver) (4/4)
19:02:02.534 INFO  TaskSchedulerImpl - Removed TaskSet 43.0, whose tasks have all completed, from pool 
19:02:02.536 INFO  DAGScheduler - ResultStage 43 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.016 s
19:02:02.536 INFO  DAGScheduler - Job 34 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:02.536 INFO  TaskSchedulerImpl - Killing all running tasks in stage 43: Stage finished
19:02:02.536 INFO  DAGScheduler - Job 34 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.017834 s
19:02:02.538 INFO  FileInputFormat - Total input files to process : 1
19:02:02.585 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
19:02:02.585 INFO  DAGScheduler - Got job 35 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
19:02:02.585 INFO  DAGScheduler - Final stage: ResultStage 44 (collect at ReadsSparkSourceUnitTest.java:112)
19:02:02.585 INFO  DAGScheduler - Parents of final stage: List()
19:02:02.586 INFO  DAGScheduler - Missing parents: List()
19:02:02.586 INFO  DAGScheduler - Submitting ResultStage 44 (MapPartitionsRDD[161] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:02.604 INFO  MemoryStore - Block broadcast_71 stored as values in memory (estimated size 425.0 KiB, free 1918.2 MiB)
19:02:02.606 INFO  MemoryStore - Block broadcast_71_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1918.0 MiB)
19:02:02.606 INFO  BlockManagerInfo - Added broadcast_71_piece0 in memory on localhost:45255 (size: 152.7 KiB, free: 1919.6 MiB)
19:02:02.606 INFO  SparkContext - Created broadcast 71 from broadcast at DAGScheduler.scala:1580
19:02:02.606 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))
19:02:02.606 INFO  TaskSchedulerImpl - Adding task set 44.0 with 1 tasks resource profile 0
19:02:02.607 INFO  TaskSetManager - Starting task 0.0 in stage 44.0 (TID 106) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7831 bytes) 
19:02:02.608 INFO  Executor - Running task 0.0 in stage 44.0 (TID 106)
19:02:02.645 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam:0+57538
19:02:02.652 INFO  Executor - Finished task 0.0 in stage 44.0 (TID 106). 159572 bytes result sent to driver
19:02:02.654 INFO  TaskSetManager - Finished task 0.0 in stage 44.0 (TID 106) in 47 ms on localhost (executor driver) (1/1)
19:02:02.654 INFO  TaskSchedulerImpl - Removed TaskSet 44.0, whose tasks have all completed, from pool 
19:02:02.654 INFO  DAGScheduler - ResultStage 44 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.068 s
19:02:02.654 INFO  DAGScheduler - Job 35 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:02.654 INFO  TaskSchedulerImpl - Killing all running tasks in stage 44: Stage finished
19:02:02.654 INFO  DAGScheduler - Job 35 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.069653 s
19:02:02.659 INFO  MemoryStore - Block broadcast_72 stored as values in memory (estimated size 528.0 B, free 1918.0 MiB)
19:02:02.660 INFO  MemoryStore - Block broadcast_72_piece0 stored as bytes in memory (estimated size 183.0 B, free 1918.0 MiB)
19:02:02.660 INFO  BlockManagerInfo - Added broadcast_72_piece0 in memory on localhost:45255 (size: 183.0 B, free: 1919.6 MiB)
19:02:02.661 INFO  SparkContext - Created broadcast 72 from broadcast at CramSource.java:114
19:02:02.664 INFO  MemoryStore - Block broadcast_73 stored as values in memory (estimated size 297.2 KiB, free 1917.7 MiB)
19:02:02.675 INFO  MemoryStore - Block broadcast_73_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1917.7 MiB)
19:02:02.675 INFO  BlockManagerInfo - Added broadcast_73_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.6 MiB)
19:02:02.675 INFO  SparkContext - Created broadcast 73 from newAPIHadoopFile at PathSplitSource.java:96
19:02:02.707 INFO  MemoryStore - Block broadcast_74 stored as values in memory (estimated size 528.0 B, free 1917.7 MiB)
19:02:02.708 INFO  MemoryStore - Block broadcast_74_piece0 stored as bytes in memory (estimated size 183.0 B, free 1917.7 MiB)
19:02:02.708 INFO  BlockManagerInfo - Added broadcast_74_piece0 in memory on localhost:45255 (size: 183.0 B, free: 1919.6 MiB)
19:02:02.708 INFO  SparkContext - Created broadcast 74 from broadcast at CramSource.java:114
19:02:02.710 INFO  MemoryStore - Block broadcast_75 stored as values in memory (estimated size 297.2 KiB, free 1917.4 MiB)
19:02:02.717 INFO  MemoryStore - Block broadcast_75_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1917.4 MiB)
19:02:02.717 INFO  BlockManagerInfo - Added broadcast_75_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.5 MiB)
19:02:02.717 INFO  SparkContext - Created broadcast 75 from newAPIHadoopFile at PathSplitSource.java:96
19:02:02.735 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:111
19:02:02.736 INFO  DAGScheduler - Got job 36 (collect at ReadsSparkSourceUnitTest.java:111) with 4 output partitions
19:02:02.736 INFO  DAGScheduler - Final stage: ResultStage 45 (collect at ReadsSparkSourceUnitTest.java:111)
19:02:02.736 INFO  DAGScheduler - Parents of final stage: List()
19:02:02.736 INFO  DAGScheduler - Missing parents: List()
19:02:02.736 INFO  DAGScheduler - Submitting ResultStage 45 (ParallelCollectionRDD[166] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:02.737 INFO  MemoryStore - Block broadcast_76 stored as values in memory (estimated size 3.0 KiB, free 1917.4 MiB)
19:02:02.738 INFO  MemoryStore - Block broadcast_76_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1917.3 MiB)
19:02:02.738 INFO  BlockManagerInfo - Added broadcast_76_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1919.5 MiB)
19:02:02.738 INFO  SparkContext - Created broadcast 76 from broadcast at DAGScheduler.scala:1580
19:02:02.738 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))
19:02:02.738 INFO  TaskSchedulerImpl - Adding task set 45.0 with 4 tasks resource profile 0
19:02:02.740 INFO  TaskSetManager - Starting task 0.0 in stage 45.0 (TID 107) (localhost, executor driver, partition 0, PROCESS_LOCAL, 45675 bytes) 
19:02:02.740 INFO  TaskSetManager - Starting task 1.0 in stage 45.0 (TID 108) (localhost, executor driver, partition 1, PROCESS_LOCAL, 45855 bytes) 
19:02:02.741 INFO  TaskSetManager - Starting task 2.0 in stage 45.0 (TID 109) (localhost, executor driver, partition 2, PROCESS_LOCAL, 45795 bytes) 
19:02:02.741 INFO  TaskSetManager - Starting task 3.0 in stage 45.0 (TID 110) (localhost, executor driver, partition 3, PROCESS_LOCAL, 46068 bytes) 
19:02:02.742 INFO  Executor - Running task 3.0 in stage 45.0 (TID 110)
19:02:02.742 INFO  Executor - Running task 1.0 in stage 45.0 (TID 108)
19:02:02.742 INFO  Executor - Running task 2.0 in stage 45.0 (TID 109)
19:02:02.743 INFO  Executor - Running task 0.0 in stage 45.0 (TID 107)
19:02:02.745 INFO  Executor - Finished task 0.0 in stage 45.0 (TID 107). 38907 bytes result sent to driver
19:02:02.745 INFO  Executor - Finished task 1.0 in stage 45.0 (TID 108). 39130 bytes result sent to driver
19:02:02.745 INFO  Executor - Finished task 2.0 in stage 45.0 (TID 109). 39070 bytes result sent to driver
19:02:02.746 INFO  TaskSetManager - Finished task 0.0 in stage 45.0 (TID 107) in 7 ms on localhost (executor driver) (1/4)
19:02:02.746 INFO  TaskSetManager - Finished task 1.0 in stage 45.0 (TID 108) in 6 ms on localhost (executor driver) (2/4)
19:02:02.747 INFO  TaskSetManager - Finished task 2.0 in stage 45.0 (TID 109) in 7 ms on localhost (executor driver) (3/4)
19:02:02.747 INFO  Executor - Finished task 3.0 in stage 45.0 (TID 110). 39343 bytes result sent to driver
19:02:02.748 INFO  TaskSetManager - Finished task 3.0 in stage 45.0 (TID 110) in 7 ms on localhost (executor driver) (4/4)
19:02:02.748 INFO  TaskSchedulerImpl - Removed TaskSet 45.0, whose tasks have all completed, from pool 
19:02:02.748 INFO  DAGScheduler - ResultStage 45 (collect at ReadsSparkSourceUnitTest.java:111) finished in 0.012 s
19:02:02.748 INFO  DAGScheduler - Job 36 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:02.748 INFO  TaskSchedulerImpl - Killing all running tasks in stage 45: Stage finished
19:02:02.748 INFO  DAGScheduler - Job 36 finished: collect at ReadsSparkSourceUnitTest.java:111, took 0.012957 s
19:02:02.749 INFO  FileInputFormat - Total input files to process : 1
19:02:02.780 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:112
19:02:02.781 INFO  DAGScheduler - Got job 37 (collect at ReadsSparkSourceUnitTest.java:112) with 1 output partitions
19:02:02.781 INFO  DAGScheduler - Final stage: ResultStage 46 (collect at ReadsSparkSourceUnitTest.java:112)
19:02:02.781 INFO  DAGScheduler - Parents of final stage: List()
19:02:02.781 INFO  DAGScheduler - Missing parents: List()
19:02:02.781 INFO  DAGScheduler - Submitting ResultStage 46 (MapPartitionsRDD[172] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:02.799 INFO  MemoryStore - Block broadcast_77 stored as values in memory (estimated size 286.0 KiB, free 1917.1 MiB)
19:02:02.801 INFO  MemoryStore - Block broadcast_77_piece0 stored as bytes in memory (estimated size 103.1 KiB, free 1917.0 MiB)
19:02:02.801 INFO  BlockManagerInfo - Added broadcast_77_piece0 in memory on localhost:45255 (size: 103.1 KiB, free: 1919.4 MiB)
19:02:02.801 INFO  SparkContext - Created broadcast 77 from broadcast at DAGScheduler.scala:1580
19:02:02.801 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))
19:02:02.801 INFO  TaskSchedulerImpl - Adding task set 46.0 with 1 tasks resource profile 0
19:02:02.802 INFO  TaskSetManager - Starting task 0.0 in stage 46.0 (TID 111) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7832 bytes) 
19:02:02.803 INFO  Executor - Running task 0.0 in stage 46.0 (TID 111)
19:02:02.840 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.cram:0+50619
19:02:02.858 INFO  Executor - Finished task 0.0 in stage 46.0 (TID 111). 154101 bytes result sent to driver
19:02:02.860 INFO  TaskSetManager - Finished task 0.0 in stage 46.0 (TID 111) in 58 ms on localhost (executor driver) (1/1)
19:02:02.860 INFO  TaskSchedulerImpl - Removed TaskSet 46.0, whose tasks have all completed, from pool 
19:02:02.860 INFO  DAGScheduler - ResultStage 46 (collect at ReadsSparkSourceUnitTest.java:112) finished in 0.078 s
19:02:02.860 INFO  DAGScheduler - Job 37 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:02.861 INFO  TaskSchedulerImpl - Killing all running tasks in stage 46: Stage finished
19:02:02.861 INFO  DAGScheduler - Job 37 finished: collect at ReadsSparkSourceUnitTest.java:112, took 0.080032 s
19:02:02.865 INFO  MemoryStore - Block broadcast_78 stored as values in memory (estimated size 297.2 KiB, free 1916.7 MiB)
19:02:02.872 INFO  MemoryStore - Block broadcast_78_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1916.6 MiB)
19:02:02.872 INFO  BlockManagerInfo - Added broadcast_78_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.4 MiB)
19:02:02.873 INFO  SparkContext - Created broadcast 78 from newAPIHadoopFile at PathSplitSource.java:96
19:02:02.897 INFO  MemoryStore - Block broadcast_79 stored as values in memory (estimated size 528.0 B, free 1916.6 MiB)
19:02:02.898 INFO  MemoryStore - Block broadcast_79_piece0 stored as bytes in memory (estimated size 183.0 B, free 1916.6 MiB)
19:02:02.898 INFO  BlockManagerInfo - Added broadcast_79_piece0 in memory on localhost:45255 (size: 183.0 B, free: 1919.4 MiB)
19:02:02.899 INFO  SparkContext - Created broadcast 79 from broadcast at CramSource.java:114
19:02:02.901 INFO  MemoryStore - Block broadcast_80 stored as values in memory (estimated size 297.2 KiB, free 1916.3 MiB)
19:02:02.907 INFO  MemoryStore - Block broadcast_80_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1916.3 MiB)
19:02:02.907 INFO  BlockManagerInfo - Added broadcast_80_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.3 MiB)
19:02:02.908 INFO  SparkContext - Created broadcast 80 from newAPIHadoopFile at PathSplitSource.java:96
19:02:02.949 WARN  FileSystem - Failed to initialize filesystem hdfs://bogus/path.bam: java.lang.IllegalArgumentException: java.net.UnknownHostException: bogus
19:02:02.955 INFO  MemoryStore - Block broadcast_81 stored as values in memory (estimated size 297.3 KiB, free 1916.0 MiB)
19:02:02.962 INFO  MemoryStore - Block broadcast_81_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1916.0 MiB)
19:02:02.962 INFO  BlockManagerInfo - Added broadcast_81_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.3 MiB)
19:02:02.963 INFO  SparkContext - Created broadcast 81 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.000 INFO  MemoryStore - Block broadcast_82 stored as values in memory (estimated size 297.3 KiB, free 1915.7 MiB)
19:02:03.007 INFO  MemoryStore - Block broadcast_82_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1915.6 MiB)
19:02:03.007 INFO  BlockManagerInfo - Added broadcast_82_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.2 MiB)
19:02:03.007 INFO  SparkContext - Created broadcast 82 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.033 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:154
19:02:03.034 INFO  DAGScheduler - Got job 38 (collect at ReadsSparkSourceUnitTest.java:154) with 4 output partitions
19:02:03.034 INFO  DAGScheduler - Final stage: ResultStage 47 (collect at ReadsSparkSourceUnitTest.java:154)
19:02:03.034 INFO  DAGScheduler - Parents of final stage: List()
19:02:03.034 INFO  DAGScheduler - Missing parents: List()
19:02:03.034 INFO  DAGScheduler - Submitting ResultStage 47 (ParallelCollectionRDD[187] at parallelize at ReadsSparkSourceUnitTest.java:310), which has no missing parents
19:02:03.035 INFO  MemoryStore - Block broadcast_83 stored as values in memory (estimated size 3.0 KiB, free 1915.6 MiB)
19:02:03.036 INFO  MemoryStore - Block broadcast_83_piece0 stored as bytes in memory (estimated size 1780.0 B, free 1915.6 MiB)
19:02:03.036 INFO  BlockManagerInfo - Added broadcast_83_piece0 in memory on localhost:45255 (size: 1780.0 B, free: 1919.2 MiB)
19:02:03.036 INFO  SparkContext - Created broadcast 83 from broadcast at DAGScheduler.scala:1580
19:02:03.036 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))
19:02:03.036 INFO  TaskSchedulerImpl - Adding task set 47.0 with 4 tasks resource profile 0
19:02:03.038 INFO  TaskSetManager - Starting task 0.0 in stage 47.0 (TID 112) (localhost, executor driver, partition 0, PROCESS_LOCAL, 169886 bytes) 
19:02:03.038 INFO  TaskSetManager - Starting task 1.0 in stage 47.0 (TID 113) (localhost, executor driver, partition 1, PROCESS_LOCAL, 170093 bytes) 
19:02:03.039 INFO  TaskSetManager - Starting task 2.0 in stage 47.0 (TID 114) (localhost, executor driver, partition 2, PROCESS_LOCAL, 170081 bytes) 
19:02:03.040 INFO  TaskSetManager - Starting task 3.0 in stage 47.0 (TID 115) (localhost, executor driver, partition 3, PROCESS_LOCAL, 169419 bytes) 
19:02:03.040 INFO  Executor - Running task 0.0 in stage 47.0 (TID 112)
19:02:03.040 INFO  Executor - Running task 1.0 in stage 47.0 (TID 113)
19:02:03.040 INFO  Executor - Running task 2.0 in stage 47.0 (TID 114)
19:02:03.041 INFO  Executor - Running task 3.0 in stage 47.0 (TID 115)
19:02:03.044 INFO  Executor - Finished task 2.0 in stage 47.0 (TID 114). 163356 bytes result sent to driver
19:02:03.045 INFO  TaskSetManager - Finished task 2.0 in stage 47.0 (TID 114) in 7 ms on localhost (executor driver) (1/4)
19:02:03.044 INFO  Executor - Finished task 3.0 in stage 47.0 (TID 115). 162694 bytes result sent to driver
19:02:03.046 INFO  Executor - Finished task 0.0 in stage 47.0 (TID 112). 163204 bytes result sent to driver
19:02:03.046 INFO  Executor - Finished task 1.0 in stage 47.0 (TID 113). 163368 bytes result sent to driver
19:02:03.047 INFO  TaskSetManager - Finished task 1.0 in stage 47.0 (TID 113) in 9 ms on localhost (executor driver) (2/4)
19:02:03.048 INFO  TaskSetManager - Finished task 0.0 in stage 47.0 (TID 112) in 11 ms on localhost (executor driver) (3/4)
19:02:03.049 INFO  TaskSetManager - Finished task 3.0 in stage 47.0 (TID 115) in 9 ms on localhost (executor driver) (4/4)
19:02:03.049 INFO  TaskSchedulerImpl - Removed TaskSet 47.0, whose tasks have all completed, from pool 
19:02:03.049 INFO  DAGScheduler - ResultStage 47 (collect at ReadsSparkSourceUnitTest.java:154) finished in 0.015 s
19:02:03.049 INFO  DAGScheduler - Job 38 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:03.049 INFO  TaskSchedulerImpl - Killing all running tasks in stage 47: Stage finished
19:02:03.049 INFO  DAGScheduler - Job 38 finished: collect at ReadsSparkSourceUnitTest.java:154, took 0.015923 s
19:02:03.059 INFO  FileInputFormat - Total input files to process : 2
19:02:03.096 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:155
19:02:03.097 INFO  DAGScheduler - Got job 39 (collect at ReadsSparkSourceUnitTest.java:155) with 2 output partitions
19:02:03.097 INFO  DAGScheduler - Final stage: ResultStage 48 (collect at ReadsSparkSourceUnitTest.java:155)
19:02:03.097 INFO  DAGScheduler - Parents of final stage: List()
19:02:03.097 INFO  DAGScheduler - Missing parents: List()
19:02:03.097 INFO  DAGScheduler - Submitting ResultStage 48 (MapPartitionsRDD[194] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:03.121 INFO  MemoryStore - Block broadcast_84 stored as values in memory (estimated size 425.0 KiB, free 1915.2 MiB)
19:02:03.122 INFO  MemoryStore - Block broadcast_84_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1915.0 MiB)
19:02:03.123 INFO  BlockManagerInfo - Added broadcast_84_piece0 in memory on localhost:45255 (size: 152.7 KiB, free: 1919.1 MiB)
19:02:03.123 INFO  SparkContext - Created broadcast 84 from broadcast at DAGScheduler.scala:1580
19:02:03.123 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))
19:02:03.123 INFO  TaskSchedulerImpl - Adding task set 48.0 with 2 tasks resource profile 0
19:02:03.124 INFO  TaskSetManager - Starting task 0.0 in stage 48.0 (TID 116) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7921 bytes) 
19:02:03.124 INFO  TaskSetManager - Starting task 1.0 in stage 48.0 (TID 117) (localhost, executor driver, partition 1, PROCESS_LOCAL, 7921 bytes) 
19:02:03.125 INFO  Executor - Running task 0.0 in stage 48.0 (TID 116)
19:02:03.125 INFO  Executor - Running task 1.0 in stage 48.0 (TID 117)
19:02:03.162 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
19:02:03.177 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
19:02:03.179 INFO  Executor - Finished task 1.0 in stage 48.0 (TID 117). 325633 bytes result sent to driver
19:02:03.181 INFO  TaskSetManager - Finished task 1.0 in stage 48.0 (TID 117) in 57 ms on localhost (executor driver) (1/2)
19:02:03.195 INFO  Executor - Finished task 0.0 in stage 48.0 (TID 116). 325633 bytes result sent to driver
19:02:03.197 INFO  TaskSetManager - Finished task 0.0 in stage 48.0 (TID 116) in 73 ms on localhost (executor driver) (2/2)
19:02:03.197 INFO  TaskSchedulerImpl - Removed TaskSet 48.0, whose tasks have all completed, from pool 
19:02:03.197 INFO  DAGScheduler - ResultStage 48 (collect at ReadsSparkSourceUnitTest.java:155) finished in 0.099 s
19:02:03.197 INFO  DAGScheduler - Job 39 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:03.197 INFO  TaskSchedulerImpl - Killing all running tasks in stage 48: Stage finished
19:02:03.197 INFO  DAGScheduler - Job 39 finished: collect at ReadsSparkSourceUnitTest.java:155, took 0.100888 s
19:02:03.204 INFO  MemoryStore - Block broadcast_85 stored as values in memory (estimated size 297.2 KiB, free 1914.8 MiB)
19:02:03.215 INFO  MemoryStore - Block broadcast_85_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1914.7 MiB)
19:02:03.215 INFO  BlockManagerInfo - Added broadcast_85_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1919.0 MiB)
19:02:03.215 INFO  SparkContext - Created broadcast 85 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.251 INFO  MemoryStore - Block broadcast_86 stored as values in memory (estimated size 297.3 KiB, free 1914.4 MiB)
19:02:03.258 INFO  MemoryStore - Block broadcast_86_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1914.4 MiB)
19:02:03.258 INFO  BlockManagerInfo - Added broadcast_86_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.0 MiB)
19:02:03.258 INFO  SparkContext - Created broadcast 86 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.282 INFO  MemoryStore - Block broadcast_87 stored as values in memory (estimated size 297.3 KiB, free 1914.1 MiB)
19:02:03.288 INFO  MemoryStore - Block broadcast_87_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1914.0 MiB)
19:02:03.289 INFO  BlockManagerInfo - Added broadcast_87_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1918.9 MiB)
19:02:03.289 INFO  SparkContext - Created broadcast 87 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.312 INFO  MemoryStore - Block broadcast_88 stored as values in memory (estimated size 528.0 B, free 1914.0 MiB)
19:02:03.312 INFO  MemoryStore - Block broadcast_88_piece0 stored as bytes in memory (estimated size 183.0 B, free 1914.0 MiB)
19:02:03.313 INFO  BlockManagerInfo - Added broadcast_88_piece0 in memory on localhost:45255 (size: 183.0 B, free: 1918.9 MiB)
19:02:03.313 INFO  SparkContext - Created broadcast 88 from broadcast at CramSource.java:114
19:02:03.315 INFO  MemoryStore - Block broadcast_89 stored as values in memory (estimated size 297.2 KiB, free 1913.7 MiB)
19:02:03.321 INFO  MemoryStore - Block broadcast_89_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1913.7 MiB)
19:02:03.322 INFO  BlockManagerInfo - Added broadcast_89_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1918.9 MiB)
19:02:03.322 INFO  SparkContext - Created broadcast 89 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.339 INFO  MemoryStore - Block broadcast_90 stored as values in memory (estimated size 600.0 B, free 1913.7 MiB)
19:02:03.340 INFO  MemoryStore - Block broadcast_90_piece0 stored as bytes in memory (estimated size 202.0 B, free 1913.7 MiB)
19:02:03.340 INFO  BlockManagerInfo - Added broadcast_90_piece0 in memory on localhost:45255 (size: 202.0 B, free: 1918.9 MiB)
19:02:03.340 INFO  SparkContext - Created broadcast 90 from broadcast at CramSource.java:114
19:02:03.342 INFO  MemoryStore - Block broadcast_91 stored as values in memory (estimated size 297.3 KiB, free 1913.4 MiB)
19:02:03.348 INFO  MemoryStore - Block broadcast_91_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1913.3 MiB)
19:02:03.348 INFO  BlockManagerInfo - Added broadcast_91_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1918.8 MiB)
19:02:03.349 INFO  SparkContext - Created broadcast 91 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.366 INFO  MemoryStore - Block broadcast_92 stored as values in memory (estimated size 297.3 KiB, free 1913.1 MiB)
19:02:03.373 INFO  MemoryStore - Block broadcast_92_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1913.0 MiB)
19:02:03.373 INFO  BlockManagerInfo - Added broadcast_92_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1918.8 MiB)
19:02:03.373 INFO  SparkContext - Created broadcast 92 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.395 INFO  FileInputFormat - Total input files to process : 1
19:02:03.431 INFO  SparkContext - Starting job: collect at ReadsSparkSourceUnitTest.java:163
19:02:03.432 INFO  DAGScheduler - Got job 40 (collect at ReadsSparkSourceUnitTest.java:163) with 1 output partitions
19:02:03.432 INFO  DAGScheduler - Final stage: ResultStage 49 (collect at ReadsSparkSourceUnitTest.java:163)
19:02:03.432 INFO  DAGScheduler - Parents of final stage: List()
19:02:03.432 INFO  DAGScheduler - Missing parents: List()
19:02:03.433 INFO  DAGScheduler - Submitting ResultStage 49 (MapPartitionsRDD[224] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:03.456 INFO  MemoryStore - Block broadcast_93 stored as values in memory (estimated size 425.0 KiB, free 1912.6 MiB)
19:02:03.457 INFO  MemoryStore - Block broadcast_93_piece0 stored as bytes in memory (estimated size 152.7 KiB, free 1912.4 MiB)
19:02:03.458 INFO  BlockManagerInfo - Added broadcast_93_piece0 in memory on localhost:45255 (size: 152.7 KiB, free: 1918.6 MiB)
19:02:03.458 INFO  SparkContext - Created broadcast 93 from broadcast at DAGScheduler.scala:1580
19:02:03.458 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))
19:02:03.458 INFO  TaskSchedulerImpl - Adding task set 49.0 with 1 tasks resource profile 0
19:02:03.459 INFO  TaskSetManager - Starting task 0.0 in stage 49.0 (TID 118) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7875 bytes) 
19:02:03.459 INFO  Executor - Running task 0.0 in stage 49.0 (TID 118)
19:02:03.492 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/BQSR/HiSeq.1mb.1RG.2k_lines.alternate.bam:0+221635
19:02:03.511 INFO  Executor - Finished task 0.0 in stage 49.0 (TID 118). 650184 bytes result sent to driver
19:02:03.515 INFO  TaskSetManager - Finished task 0.0 in stage 49.0 (TID 118) in 56 ms on localhost (executor driver) (1/1)
19:02:03.515 INFO  TaskSchedulerImpl - Removed TaskSet 49.0, whose tasks have all completed, from pool 
19:02:03.515 INFO  DAGScheduler - ResultStage 49 (collect at ReadsSparkSourceUnitTest.java:163) finished in 0.082 s
19:02:03.515 INFO  DAGScheduler - Job 40 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:03.515 INFO  TaskSchedulerImpl - Killing all running tasks in stage 49: Stage finished
19:02:03.515 INFO  DAGScheduler - Job 40 finished: collect at ReadsSparkSourceUnitTest.java:163, took 0.083678 s
19:02:03.518 INFO  MemoryStore - Block broadcast_94 stored as values in memory (estimated size 208.0 B, free 1912.4 MiB)
19:02:03.520 INFO  MemoryStore - Block broadcast_94_piece0 stored as bytes in memory (estimated size 239.0 B, free 1912.4 MiB)
19:02:03.521 INFO  BlockManagerInfo - Added broadcast_94_piece0 in memory on localhost:45255 (size: 239.0 B, free: 1918.6 MiB)
19:02:03.521 INFO  SparkContext - Created broadcast 94 from broadcast at AbstractBinarySamSource.java:82
19:02:03.523 INFO  MemoryStore - Block broadcast_95 stored as values in memory (estimated size 297.2 KiB, free 1912.2 MiB)
19:02:03.529 INFO  MemoryStore - Block broadcast_95_piece0 stored as bytes in memory (estimated size 50.0 KiB, free 1912.1 MiB)
19:02:03.529 INFO  BlockManagerInfo - Added broadcast_95_piece0 in memory on localhost:45255 (size: 50.0 KiB, free: 1918.6 MiB)
19:02:03.530 INFO  SparkContext - Created broadcast 95 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.552 INFO  FileInputFormat - Total input files to process : 1
19:02:03.556 INFO  SparkContext - Starting job: count at ReadsSparkSourceUnitTest.java:265
19:02:03.556 INFO  DAGScheduler - Got job 41 (count at ReadsSparkSourceUnitTest.java:265) with 1 output partitions
19:02:03.556 INFO  DAGScheduler - Final stage: ResultStage 50 (count at ReadsSparkSourceUnitTest.java:265)
19:02:03.556 INFO  DAGScheduler - Parents of final stage: List()
19:02:03.556 INFO  DAGScheduler - Missing parents: List()
19:02:03.556 INFO  DAGScheduler - Submitting ResultStage 50 (MapPartitionsRDD[231] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:03.574 INFO  MemoryStore - Block broadcast_96 stored as values in memory (estimated size 424.9 KiB, free 1911.7 MiB)
19:02:03.575 INFO  MemoryStore - Block broadcast_96_piece0 stored as bytes in memory (estimated size 152.8 KiB, free 1911.5 MiB)
19:02:03.576 INFO  BlockManagerInfo - Added broadcast_96_piece0 in memory on localhost:45255 (size: 152.8 KiB, free: 1918.4 MiB)
19:02:03.576 INFO  SparkContext - Created broadcast 96 from broadcast at DAGScheduler.scala:1580
19:02:03.576 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))
19:02:03.576 INFO  TaskSchedulerImpl - Adding task set 50.0 with 1 tasks resource profile 0
19:02:03.577 INFO  TaskSetManager - Starting task 0.0 in stage 50.0 (TID 119) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7831 bytes) 
19:02:03.577 INFO  Executor - Running task 0.0 in stage 50.0 (TID 119)
19:02:03.611 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/NA12878.chr17_69k_70k.dictFix.bam:0+57538
19:02:03.627 INFO  BlockManagerInfo - Removed broadcast_71_piece0 on localhost:45255 in memory (size: 152.7 KiB, free: 1918.6 MiB)
19:02:03.628 INFO  BlockManagerInfo - Removed broadcast_90_piece0 on localhost:45255 in memory (size: 202.0 B, free: 1918.6 MiB)
19:02:03.628 INFO  BlockManagerInfo - Removed broadcast_74_piece0 on localhost:45255 in memory (size: 183.0 B, free: 1918.6 MiB)
19:02:03.629 INFO  Executor - Finished task 0.0 in stage 50.0 (TID 119). 1032 bytes result sent to driver
19:02:03.630 INFO  TaskSetManager - Finished task 0.0 in stage 50.0 (TID 119) in 53 ms on localhost (executor driver) (1/1)
19:02:03.630 INFO  TaskSchedulerImpl - Removed TaskSet 50.0, whose tasks have all completed, from pool 
19:02:03.630 INFO  DAGScheduler - ResultStage 50 (count at ReadsSparkSourceUnitTest.java:265) finished in 0.073 s
19:02:03.630 INFO  BlockManagerInfo - Removed broadcast_77_piece0 on localhost:45255 in memory (size: 103.1 KiB, free: 1918.7 MiB)
19:02:03.630 INFO  DAGScheduler - Job 41 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:03.630 INFO  TaskSchedulerImpl - Killing all running tasks in stage 50: Stage finished
19:02:03.630 INFO  DAGScheduler - Job 41 finished: count at ReadsSparkSourceUnitTest.java:265, took 0.074632 s
19:02:03.632 INFO  BlockManagerInfo - Removed broadcast_73_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1918.7 MiB)
19:02:03.633 INFO  BlockManagerInfo - Removed broadcast_81_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1918.8 MiB)
19:02:03.634 INFO  BlockManagerInfo - Removed broadcast_72_piece0 on localhost:45255 in memory (size: 183.0 B, free: 1918.8 MiB)
19:02:03.635 INFO  BlockManagerInfo - Removed broadcast_69_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1918.8 MiB)
19:02:03.635 INFO  MemoryStore - Block broadcast_97 stored as values in memory (estimated size 160.0 B, free 1913.5 MiB)
19:02:03.635 INFO  BlockManagerInfo - Removed broadcast_79_piece0 on localhost:45255 in memory (size: 183.0 B, free: 1918.8 MiB)
19:02:03.636 INFO  BlockManagerInfo - Removed broadcast_68_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1918.9 MiB)
19:02:03.637 INFO  BlockManagerInfo - Removed broadcast_64_piece0 on localhost:45255 in memory (size: 183.0 B, free: 1918.9 MiB)
19:02:03.637 INFO  MemoryStore - Block broadcast_97_piece0 stored as bytes in memory (estimated size 229.0 B, free 1913.8 MiB)
19:02:03.637 INFO  BlockManagerInfo - Added broadcast_97_piece0 in memory on localhost:45255 (size: 229.0 B, free: 1918.9 MiB)
19:02:03.637 INFO  SparkContext - Created broadcast 97 from broadcast at AbstractBinarySamSource.java:82
19:02:03.638 INFO  BlockManagerInfo - Removed broadcast_84_piece0 on localhost:45255 in memory (size: 152.7 KiB, free: 1919.0 MiB)
19:02:03.639 INFO  BlockManagerInfo - Removed broadcast_75_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.1 MiB)
19:02:03.639 INFO  MemoryStore - Block broadcast_98 stored as values in memory (estimated size 297.3 KiB, free 1914.5 MiB)
19:02:03.640 INFO  BlockManagerInfo - Removed broadcast_67_piece0 on localhost:45255 in memory (size: 103.1 KiB, free: 1919.2 MiB)
19:02:03.641 INFO  BlockManagerInfo - Removed broadcast_92_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.2 MiB)
19:02:03.642 INFO  BlockManagerInfo - Removed broadcast_83_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.2 MiB)
19:02:03.643 INFO  BlockManagerInfo - Removed broadcast_70_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.2 MiB)
19:02:03.644 INFO  BlockManagerInfo - Removed broadcast_86_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.3 MiB)
19:02:03.645 INFO  BlockManagerInfo - Removed broadcast_89_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.3 MiB)
19:02:03.645 INFO  BlockManagerInfo - Removed broadcast_78_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.4 MiB)
19:02:03.646 INFO  BlockManagerInfo - Removed broadcast_80_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.4 MiB)
19:02:03.647 INFO  BlockManagerInfo - Removed broadcast_65_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.5 MiB)
19:02:03.648 INFO  BlockManagerInfo - Removed broadcast_82_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.5 MiB)
19:02:03.649 INFO  BlockManagerInfo - Removed broadcast_88_piece0 on localhost:45255 in memory (size: 183.0 B, free: 1919.5 MiB)
19:02:03.650 INFO  BlockManagerInfo - Removed broadcast_76_piece0 on localhost:45255 in memory (size: 1780.0 B, free: 1919.5 MiB)
19:02:03.650 INFO  MemoryStore - Block broadcast_98_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1917.2 MiB)
19:02:03.650 INFO  BlockManagerInfo - Added broadcast_98_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.5 MiB)
19:02:03.651 INFO  BlockManagerInfo - Removed broadcast_85_piece0 on localhost:45255 in memory (size: 50.0 KiB, free: 1919.5 MiB)
19:02:03.651 INFO  SparkContext - Created broadcast 98 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.651 INFO  BlockManagerInfo - Removed broadcast_87_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.6 MiB)
19:02:03.652 INFO  BlockManagerInfo - Removed broadcast_91_piece0 on localhost:45255 in memory (size: 50.1 KiB, free: 1919.6 MiB)
19:02:03.653 INFO  BlockManagerInfo - Removed broadcast_93_piece0 on localhost:45255 in memory (size: 152.7 KiB, free: 1919.8 MiB)
19:02:03.677 INFO  FileInputFormat - Total input files to process : 1
19:02:03.680 INFO  SparkContext - Starting job: count at ReadsSparkSourceUnitTest.java:286
19:02:03.681 INFO  DAGScheduler - Got job 42 (count at ReadsSparkSourceUnitTest.java:286) with 1 output partitions
19:02:03.681 INFO  DAGScheduler - Final stage: ResultStage 51 (count at ReadsSparkSourceUnitTest.java:286)
19:02:03.681 INFO  DAGScheduler - Parents of final stage: List()
19:02:03.681 INFO  DAGScheduler - Missing parents: List()
19:02:03.681 INFO  DAGScheduler - Submitting ResultStage 51 (MapPartitionsRDD[238] at filter at ReadsSparkSource.java:96), which has no missing parents
19:02:03.699 INFO  MemoryStore - Block broadcast_99 stored as values in memory (estimated size 424.9 KiB, free 1918.3 MiB)
19:02:03.700 INFO  MemoryStore - Block broadcast_99_piece0 stored as bytes in memory (estimated size 152.8 KiB, free 1918.2 MiB)
19:02:03.701 INFO  BlockManagerInfo - Added broadcast_99_piece0 in memory on localhost:45255 (size: 152.8 KiB, free: 1919.6 MiB)
19:02:03.701 INFO  SparkContext - Created broadcast 99 from broadcast at DAGScheduler.scala:1580
19:02:03.701 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))
19:02:03.701 INFO  TaskSchedulerImpl - Adding task set 51.0 with 1 tasks resource profile 0
19:02:03.702 INFO  TaskSetManager - Starting task 0.0 in stage 51.0 (TID 120) (localhost, executor driver, partition 0, PROCESS_LOCAL, 7891 bytes) 
19:02:03.702 INFO  Executor - Running task 0.0 in stage 51.0 (TID 120)
19:02:03.737 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/engine/CEUTrio.HiSeq.WGS.b37.NA12878.snippet_with_unmapped.bam:0+2184
19:02:03.744 INFO  Executor - Finished task 0.0 in stage 51.0 (TID 120). 989 bytes result sent to driver
19:02:03.745 INFO  TaskSetManager - Finished task 0.0 in stage 51.0 (TID 120) in 43 ms on localhost (executor driver) (1/1)
19:02:03.745 INFO  TaskSchedulerImpl - Removed TaskSet 51.0, whose tasks have all completed, from pool 
19:02:03.745 INFO  DAGScheduler - ResultStage 51 (count at ReadsSparkSourceUnitTest.java:286) finished in 0.064 s
19:02:03.745 INFO  DAGScheduler - Job 42 is finished. Cancelling potential speculative or zombie tasks for this job
19:02:03.745 INFO  TaskSchedulerImpl - Killing all running tasks in stage 51: Stage finished
19:02:03.745 INFO  DAGScheduler - Job 42 finished: count at ReadsSparkSourceUnitTest.java:286, took 0.065118 s
19:02:03.751 INFO  MemoryStore - Block broadcast_100 stored as values in memory (estimated size 297.3 KiB, free 1917.9 MiB)
19:02:03.762 INFO  MemoryStore - Block broadcast_100_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1917.9 MiB)
19:02:03.762 INFO  BlockManagerInfo - Added broadcast_100_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.6 MiB)
19:02:03.763 INFO  SparkContext - Created broadcast 100 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.796 INFO  MemoryStore - Block broadcast_101 stored as values in memory (estimated size 297.4 KiB, free 1917.6 MiB)
19:02:03.802 INFO  MemoryStore - Block broadcast_101_piece0 stored as bytes in memory (estimated size 50.1 KiB, free 1917.5 MiB)
19:02:03.803 INFO  BlockManagerInfo - Added broadcast_101_piece0 in memory on localhost:45255 (size: 50.1 KiB, free: 1919.5 MiB)
19:02:03.803 INFO  SparkContext - Created broadcast 101 from newAPIHadoopFile at PathSplitSource.java:96
19:02:03.825 INFO  FileInputFormat - Total input files to process : 1
19:02:03.826 INFO  FileInputFormat - Total input files to process : 1