[May 27, 2025 at 6:16:11 PM UTC] org.broadinstitute.hellbender.tools.spark.pipelines.metrics.CollectMultipleMetricsSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1432354816
[May 27, 2025 at 6:16:11 PM UTC] org.broadinstitute.hellbender.tools.spark.pipelines.metrics.CollectMultipleMetricsSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1432354816
[May 27, 2025 at 6:16:11 PM UTC] org.broadinstitute.hellbender.tools.spark.pipelines.metrics.CollectMultipleMetricsSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1432354816
18:16:11.935 INFO CollectMultipleMetricsSpark - ------------------------------------------------------------
18:16:11.935 INFO CollectMultipleMetricsSpark - org.broadinstitute.hellbender.tools.spark.pipelines.metrics vUnavailable
18:16:11.935 INFO CollectMultipleMetricsSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
18:16:11.935 INFO CollectMultipleMetricsSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
18:16:11.935 INFO CollectMultipleMetricsSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
18:16:11.935 INFO CollectMultipleMetricsSpark - Start Date/Time: May 27, 2025 at 6:16:11 PM UTC
18:16:11.935 INFO CollectMultipleMetricsSpark - ------------------------------------------------------------
18:16:11.935 INFO CollectMultipleMetricsSpark - ------------------------------------------------------------
18:16:11.935 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
18:16:11.935 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
18:16:11.935 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
18:16:11.935 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
18:16:11.935 INFO CollectMultipleMetricsSpark - Deflater: IntelDeflater
18:16:11.935 INFO CollectMultipleMetricsSpark - Inflater: IntelInflater
18:16:11.935 INFO CollectMultipleMetricsSpark - GCS max retries/reopens: 20
18:16:11.935 INFO CollectMultipleMetricsSpark - Requester pays: disabled
18:16:11.935 WARN CollectMultipleMetricsSpark -
?[1m?[31m !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Warning: CollectMultipleMetricsSpark is a BETA tool and is not yet ready for use in production
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!?[0m
18:16:11.935 INFO CollectMultipleMetricsSpark - Initializing engine
18:16:11.935 INFO CollectMultipleMetricsSpark - Done initializing engine
18:16:11.935 INFO CollectMultipleMetricsSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
WARNING 2025-05-27 18:16:11 SamReaderFactory Unable to detect file format from input URL or stream, assuming SAM format.
WARNING 2025-05-27 18:16:11 SamReaderFactory Unable to detect file format from input URL or stream, assuming SAM format.
18:16:11.937 INFO MemoryStore - Block broadcast_3408 stored as values in memory (estimated size 37.8 KiB, free 1907.2 MiB)
18:16:11.937 INFO MemoryStore - Block broadcast_3408_piece0 stored as bytes in memory (estimated size 8.4 KiB, free 1907.2 MiB)
18:16:11.937 INFO BlockManagerInfo - Added broadcast_3408_piece0 in memory on localhost:44275 (size: 8.4 KiB, free: 1916.8 MiB)
18:16:11.937 INFO SparkContext - Created broadcast 3408 from broadcast at SamSource.java:78
18:16:11.938 INFO MemoryStore - Block broadcast_3409 stored as values in memory (estimated size 306.3 KiB, free 1906.9 MiB)
18:16:11.944 INFO MemoryStore - Block broadcast_3409_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1906.9 MiB)
18:16:11.945 INFO BlockManagerInfo - Added broadcast_3409_piece0 in memory on localhost:44275 (size: 64.4 KiB, free: 1916.8 MiB)
18:16:11.945 INFO SparkContext - Created broadcast 3409 from newAPIHadoopFile at SamSource.java:108
WARNING 2025-05-27 18:16:11 SamReaderFactory Unable to detect file format from input URL or stream, assuming SAM format.
WARNING 2025-05-27 18:16:11 SamReaderFactory Unable to detect file format from input URL or stream, assuming SAM format.
18:16:11.947 INFO MemoryStore - Block broadcast_3410 stored as values in memory (estimated size 37.8 KiB, free 1906.8 MiB)
18:16:11.947 INFO MemoryStore - Block broadcast_3410_piece0 stored as bytes in memory (estimated size 8.4 KiB, free 1906.8 MiB)
18:16:11.947 INFO BlockManagerInfo - Added broadcast_3410_piece0 in memory on localhost:44275 (size: 8.4 KiB, free: 1916.8 MiB)
18:16:11.947 INFO SparkContext - Created broadcast 3410 from broadcast at SamSource.java:78
18:16:11.948 INFO MemoryStore - Block broadcast_3411 stored as values in memory (estimated size 306.3 KiB, free 1906.5 MiB)
18:16:11.954 INFO MemoryStore - Block broadcast_3411_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1906.5 MiB)
18:16:11.954 INFO BlockManagerInfo - Added broadcast_3411_piece0 in memory on localhost:44275 (size: 64.4 KiB, free: 1916.7 MiB)
18:16:11.955 INFO SparkContext - Created broadcast 3411 from newAPIHadoopFile at SamSource.java:108
18:16:11.957 INFO FileInputFormat - Total input files to process : 1
18:16:11.960 INFO SparkContext - Starting job: count at CollectMultipleMetricsSparkIntegrationTest.java:130
18:16:11.960 INFO DAGScheduler - Got job 892 (count at CollectMultipleMetricsSparkIntegrationTest.java:130) with 1 output partitions
18:16:11.960 INFO DAGScheduler - Final stage: ResultStage 2485 (count at CollectMultipleMetricsSparkIntegrationTest.java:130)
18:16:11.960 INFO DAGScheduler - Parents of final stage: List()
18:16:11.960 INFO DAGScheduler - Missing parents: List()
18:16:11.960 INFO DAGScheduler - Submitting ResultStage 2485 (MapPartitionsRDD[10243] at filter at CollectMultipleMetricsSpark.java:193), which has no missing parents
18:16:11.961 INFO MemoryStore - Block broadcast_3412 stored as values in memory (estimated size 34.8 KiB, free 1906.4 MiB)
18:16:11.961 INFO MemoryStore - Block broadcast_3412_piece0 stored as bytes in memory (estimated size 14.6 KiB, free 1906.4 MiB)
18:16:11.961 INFO BlockManagerInfo - Added broadcast_3412_piece0 in memory on localhost:44275 (size: 14.6 KiB, free: 1916.7 MiB)
18:16:11.961 INFO SparkContext - Created broadcast 3412 from broadcast at DAGScheduler.scala:1580
18:16:11.961 INFO DAGScheduler - Submitting 1 missing tasks from ResultStage 2485 (MapPartitionsRDD[10243] at filter at CollectMultipleMetricsSpark.java:193) (first 15 tasks are for partitions Vector(0))
18:16:11.961 INFO TaskSchedulerImpl - Adding task set 2485.0 with 1 tasks resource profile 0
18:16:11.962 INFO TaskSetManager - Starting task 0.0 in stage 2485.0 (TID 1916) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9772 bytes)
18:16:11.962 INFO Executor - Running task 0.0 in stage 2485.0 (TID 1916)
18:16:11.963 INFO NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/metrics/analysis/CollectInsertSizeMetrics/insert_size_metrics_test.sam:0+44008
18:16:11.964 INFO Executor - Finished task 0.0 in stage 2485.0 (TID 1916). 946 bytes result sent to driver
18:16:11.964 INFO TaskSetManager - Finished task 0.0 in stage 2485.0 (TID 1916) in 2 ms on localhost (executor driver) (1/1)
18:16:11.964 INFO TaskSchedulerImpl - Removed TaskSet 2485.0, whose tasks have all completed, from pool
18:16:11.964 INFO DAGScheduler - ResultStage 2485 (count at CollectMultipleMetricsSparkIntegrationTest.java:130) finished in 0.004 s
18:16:11.964 INFO DAGScheduler - Job 892 is finished. Cancelling potential speculative or zombie tasks for this job
18:16:11.964 INFO TaskSchedulerImpl - Killing all running tasks in stage 2485: Stage finished
18:16:11.965 INFO DAGScheduler - Job 892 finished: count at CollectMultipleMetricsSparkIntegrationTest.java:130, took 0.004685 s
18:16:11.965 INFO CollectMultipleMetricsSpark - Shutting down engine
[May 27, 2025 at 6:16:11 PM UTC] org.broadinstitute.hellbender.tools.spark.pipelines.metrics.CollectMultipleMetricsSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1432354816
18:16:11.969 INFO CollectMultipleMetricsSpark - ------------------------------------------------------------
18:16:11.969 INFO CollectMultipleMetricsSpark - org.broadinstitute.hellbender.tools.spark.pipelines.metrics vUnavailable
18:16:11.969 INFO CollectMultipleMetricsSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
18:16:11.969 INFO CollectMultipleMetricsSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
18:16:11.969 INFO CollectMultipleMetricsSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
18:16:11.969 INFO CollectMultipleMetricsSpark - Start Date/Time: May 27, 2025 at 6:16:11 PM UTC
18:16:11.969 INFO CollectMultipleMetricsSpark - ------------------------------------------------------------
18:16:11.969 INFO CollectMultipleMetricsSpark - ------------------------------------------------------------
18:16:11.969 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
18:16:11.969 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
18:16:11.969 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
18:16:11.969 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
18:16:11.969 INFO CollectMultipleMetricsSpark - Deflater: IntelDeflater
18:16:11.969 INFO CollectMultipleMetricsSpark - Inflater: IntelInflater
18:16:11.969 INFO CollectMultipleMetricsSpark - GCS max retries/reopens: 20
18:16:11.969 INFO CollectMultipleMetricsSpark - Requester pays: disabled
18:16:11.969 WARN CollectMultipleMetricsSpark -
?[1m?[31m !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Warning: CollectMultipleMetricsSpark is a BETA tool and is not yet ready for use in production
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!?[0m
18:16:11.969 INFO CollectMultipleMetricsSpark - Initializing engine
18:16:11.969 INFO CollectMultipleMetricsSpark - Done initializing engine
18:16:11.969 INFO CollectMultipleMetricsSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
18:16:11.971 INFO MemoryStore - Block broadcast_3413 stored as values in memory (estimated size 306.3 KiB, free 1906.1 MiB)
18:16:11.977 INFO MemoryStore - Block broadcast_3413_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1906.1 MiB)
18:16:11.977 INFO BlockManagerInfo - Added broadcast_3413_piece0 in memory on localhost:44275 (size: 64.4 KiB, free: 1916.6 MiB)
18:16:11.977 INFO SparkContext - Created broadcast 3413 from newAPIHadoopFile at PathSplitSource.java:96
18:16:11.997 INFO MemoryStore - Block broadcast_3414 stored as values in memory (estimated size 306.3 KiB, free 1905.8 MiB)
18:16:12.003 INFO MemoryStore - Block broadcast_3414_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1905.7 MiB)
18:16:12.003 INFO BlockManagerInfo - Added broadcast_3414_piece0 in memory on localhost:44275 (size: 64.4 KiB, free: 1916.5 MiB)
18:16:12.003 INFO SparkContext - Created broadcast 3414 from newAPIHadoopFile at PathSplitSource.java:96
18:16:12.011 INFO BlockManagerInfo - Removed broadcast_3396_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1916.6 MiB)
18:16:12.011 INFO BlockManagerInfo - Removed broadcast_3400_piece0 on localhost:44275 in memory (size: 208.5 KiB, free: 1916.8 MiB)
18:16:12.011 INFO BlockManagerInfo - Removed broadcast_3377_piece0 on localhost:44275 in memory (size: 214.0 B, free: 1916.8 MiB)
18:16:12.011 INFO BlockManagerInfo - Removed broadcast_3389_piece0 on localhost:44275 in memory (size: 8.4 KiB, free: 1916.8 MiB)
18:16:12.012 INFO BlockManagerInfo - Removed broadcast_3411_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1916.9 MiB)
18:16:12.012 INFO BlockManagerInfo - Removed broadcast_3387_piece0 on localhost:44275 in memory (size: 201.2 KiB, free: 1917.1 MiB)
18:16:12.012 INFO BlockManagerInfo - Removed broadcast_3386_piece0 on localhost:44275 in memory (size: 411.0 B, free: 1917.1 MiB)
18:16:12.013 INFO BlockManagerInfo - Removed broadcast_3366_piece0 on localhost:44275 in memory (size: 70.7 KiB, free: 1917.2 MiB)
18:16:12.013 INFO BlockManagerInfo - Removed broadcast_3379_piece0 on localhost:44275 in memory (size: 799.0 B, free: 1917.2 MiB)
18:16:12.013 INFO BlockManager - Removing RDD 10218
18:16:12.014 INFO BlockManagerInfo - Removed broadcast_3401_piece0 on localhost:44275 in memory (size: 211.0 B, free: 1917.2 MiB)
18:16:12.014 INFO BlockManagerInfo - Removed broadcast_3410_piece0 on localhost:44275 in memory (size: 8.4 KiB, free: 1917.2 MiB)
18:16:12.014 INFO BlockManagerInfo - Removed broadcast_3362_piece0 on localhost:44275 in memory (size: 64.3 KiB, free: 1917.2 MiB)
18:16:12.015 INFO BlockManagerInfo - Removed broadcast_3395_piece0 on localhost:44275 in memory (size: 15.2 KiB, free: 1917.3 MiB)
18:16:12.015 INFO BlockManagerInfo - Removed broadcast_3373_piece0 on localhost:44275 in memory (size: 137.3 KiB, free: 1917.4 MiB)
18:16:12.015 INFO BlockManagerInfo - Removed broadcast_3376_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1917.5 MiB)
18:16:12.016 INFO BlockManagerInfo - Removed broadcast_3398_piece0 on localhost:44275 in memory (size: 209.8 KiB, free: 1917.7 MiB)
18:16:12.016 INFO BlockManagerInfo - Removed broadcast_3382_piece0 on localhost:44275 in memory (size: 70.7 KiB, free: 1917.7 MiB)
18:16:12.016 INFO BlockManagerInfo - Removed broadcast_3394_piece0 on localhost:44275 in memory (size: 19.0 KiB, free: 1917.8 MiB)
18:16:12.016 INFO BlockManagerInfo - Removed broadcast_3369_piece0 on localhost:44275 in memory (size: 214.0 B, free: 1917.8 MiB)
18:16:12.017 INFO BlockManagerInfo - Removed broadcast_3397_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1917.8 MiB)
18:16:12.017 INFO BlockManagerInfo - Removed broadcast_3367_piece0 on localhost:44275 in memory (size: 214.0 B, free: 1917.8 MiB)
18:16:12.017 INFO BlockManagerInfo - Removed broadcast_3364_piece0 on localhost:44275 in memory (size: 411.0 B, free: 1917.8 MiB)
18:16:12.018 INFO BlockManagerInfo - Removed broadcast_3407_piece0 on localhost:44275 in memory (size: 144.3 KiB, free: 1918.0 MiB)
18:16:12.018 INFO BlockManagerInfo - Removed broadcast_3409_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1918.0 MiB)
18:16:12.018 INFO BlockManagerInfo - Removed broadcast_3399_piece0 on localhost:44275 in memory (size: 212.3 KiB, free: 1918.2 MiB)
18:16:12.019 INFO BlockManagerInfo - Removed broadcast_3380_piece0 on localhost:44275 in memory (size: 799.0 B, free: 1918.2 MiB)
18:16:12.019 INFO BlockManagerInfo - Removed broadcast_3391_piece0 on localhost:44275 in memory (size: 8.4 KiB, free: 1918.2 MiB)
18:16:12.019 INFO BlockManagerInfo - Removed broadcast_3363_piece0 on localhost:44275 in memory (size: 411.0 B, free: 1918.2 MiB)
18:16:12.019 INFO BlockManagerInfo - Removed broadcast_3413_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1918.3 MiB)
18:16:12.020 INFO BlockManagerInfo - Removed broadcast_3406_piece0 on localhost:44275 in memory (size: 148.2 KiB, free: 1918.4 MiB)
18:16:12.020 INFO BlockManagerInfo - Removed broadcast_3361_piece0 on localhost:44275 in memory (size: 64.3 KiB, free: 1918.5 MiB)
18:16:12.020 INFO BlockManagerInfo - Removed broadcast_3393_piece0 on localhost:44275 in memory (size: 16.5 KiB, free: 1918.5 MiB)
18:16:12.021 INFO BlockManagerInfo - Removed broadcast_3381_piece0 on localhost:44275 in memory (size: 137.3 KiB, free: 1918.7 MiB)
18:16:12.021 INFO BlockManagerInfo - Removed broadcast_3365_piece0 on localhost:44275 in memory (size: 201.2 KiB, free: 1918.9 MiB)
18:16:12.021 INFO BlockManager - Removing RDD 10203
18:16:12.021 INFO BlockManagerInfo - Removed broadcast_3403_piece0 on localhost:44275 in memory (size: 211.0 B, free: 1918.9 MiB)
18:16:12.022 INFO BlockManagerInfo - Removed broadcast_3405_piece0 on localhost:44275 in memory (size: 145.7 KiB, free: 1919.0 MiB)
18:16:12.022 INFO BlockManagerInfo - Removed broadcast_3392_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1919.1 MiB)
18:16:12.022 INFO BlockManagerInfo - Removed broadcast_3385_piece0 on localhost:44275 in memory (size: 411.0 B, free: 1919.1 MiB)
18:16:12.023 INFO BlockManagerInfo - Removed broadcast_3402_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1919.2 MiB)
18:16:12.023 INFO BlockManager - Removing RDD 10231
18:16:12.023 INFO BlockManagerInfo - Removed broadcast_3372_piece0 on localhost:44275 in memory (size: 799.0 B, free: 1919.2 MiB)
18:16:12.023 INFO BlockManagerInfo - Removed broadcast_3370_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1919.3 MiB)
18:16:12.024 INFO BlockManagerInfo - Removed broadcast_3388_piece0 on localhost:44275 in memory (size: 70.7 KiB, free: 1919.3 MiB)
18:16:12.024 INFO BlockManagerInfo - Removed broadcast_3404_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1919.4 MiB)
18:16:12.024 INFO BlockManagerInfo - Removed broadcast_3375_piece0 on localhost:44275 in memory (size: 214.0 B, free: 1919.4 MiB)
18:16:12.024 INFO BlockManagerInfo - Removed broadcast_3390_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1919.5 MiB)
18:16:12.025 INFO BlockManagerInfo - Removed broadcast_3383_piece0 on localhost:44275 in memory (size: 64.3 KiB, free: 1919.5 MiB)
18:16:12.025 INFO BlockManagerInfo - Removed broadcast_3408_piece0 on localhost:44275 in memory (size: 8.4 KiB, free: 1919.5 MiB)
18:16:12.025 INFO BlockManagerInfo - Removed broadcast_3378_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1919.6 MiB)
18:16:12.025 INFO BlockManagerInfo - Removed broadcast_3371_piece0 on localhost:44275 in memory (size: 799.0 B, free: 1919.6 MiB)
18:16:12.026 INFO BlockManagerInfo - Removed broadcast_3412_piece0 on localhost:44275 in memory (size: 14.6 KiB, free: 1919.6 MiB)
18:16:12.026 INFO BlockManagerInfo - Removed broadcast_3384_piece0 on localhost:44275 in memory (size: 64.3 KiB, free: 1919.7 MiB)
18:16:12.026 INFO BlockManagerInfo - Removed broadcast_3368_piece0 on localhost:44275 in memory (size: 64.4 KiB, free: 1919.7 MiB)
18:16:12.026 INFO BlockManagerInfo - Removed broadcast_3374_piece0 on localhost:44275 in memory (size: 70.7 KiB, free: 1919.8 MiB)
18:16:12.036 INFO FileInputFormat - Total input files to process : 1
18:16:12.039 INFO SparkContext - Starting job: count at CollectMultipleMetricsSparkIntegrationTest.java:130
18:16:12.039 INFO DAGScheduler - Got job 893 (count at CollectMultipleMetricsSparkIntegrationTest.java:130) with 1 output partitions
18:16:12.039 INFO DAGScheduler - Final stage: ResultStage 2486 (count at CollectMultipleMetricsSparkIntegrationTest.java:130)
18:16:12.039 INFO DAGScheduler - Parents of final stage: List()
18:16:12.039 INFO DAGScheduler - Missing parents: List()
18:16:12.039 INFO DAGScheduler - Submitting ResultStage 2486 (MapPartitionsRDD[10256] at filter at CollectMultipleMetricsSpark.java:193), which has no missing parents
18:16:12.056 INFO MemoryStore - Block broadcast_3415 stored as values in memory (estimated size 478.0 KiB, free 1918.4 MiB)
18:16:12.058 INFO MemoryStore - Block broadcast_3415_piece0 stored as bytes in memory (estimated size 208.0 KiB, free 1918.2 MiB)
18:16:12.058 INFO BlockManagerInfo - Added broadcast_3415_piece0 in memory on localhost:44275 (size: 208.0 KiB, free: 1919.6 MiB)
18:16:12.058 INFO SparkContext - Created broadcast 3415 from broadcast at DAGScheduler.scala:1580
18:16:12.058 INFO DAGScheduler - Submitting 1 missing tasks from ResultStage 2486 (MapPartitionsRDD[10256] at filter at CollectMultipleMetricsSpark.java:193) (first 15 tasks are for partitions Vector(0))
18:16:12.058 INFO TaskSchedulerImpl - Adding task set 2486.0 with 1 tasks resource profile 0
18:16:12.059 INFO TaskSetManager - Starting task 0.0 in stage 2486.0 (TID 1917) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9772 bytes)
18:16:12.059 INFO Executor - Running task 0.0 in stage 2486.0 (TID 1917)
18:16:12.088 INFO NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/metrics/analysis/CollectInsertSizeMetrics/insert_size_metrics_test.bam:0+8071
18:16:12.091 INFO Executor - Finished task 0.0 in stage 2486.0 (TID 1917). 989 bytes result sent to driver
18:16:12.091 INFO TaskSetManager - Finished task 0.0 in stage 2486.0 (TID 1917) in 32 ms on localhost (executor driver) (1/1)
18:16:12.091 INFO TaskSchedulerImpl - Removed TaskSet 2486.0, whose tasks have all completed, from pool
18:16:12.091 INFO DAGScheduler - ResultStage 2486 (count at CollectMultipleMetricsSparkIntegrationTest.java:130) finished in 0.052 s
18:16:12.091 INFO DAGScheduler - Job 893 is finished. Cancelling potential speculative or zombie tasks for this job
18:16:12.091 INFO TaskSchedulerImpl - Killing all running tasks in stage 2486: Stage finished
18:16:12.092 INFO DAGScheduler - Job 893 finished: count at CollectMultipleMetricsSparkIntegrationTest.java:130, took 0.052567 s
18:16:12.092 INFO CollectMultipleMetricsSpark - Shutting down engine
[May 27, 2025 at 6:16:12 PM UTC] org.broadinstitute.hellbender.tools.spark.pipelines.metrics.CollectMultipleMetricsSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1432354816
18:16:12.096 INFO CollectMultipleMetricsSpark - ------------------------------------------------------------
18:16:12.096 INFO CollectMultipleMetricsSpark - org.broadinstitute.hellbender.tools.spark.pipelines.metrics vUnavailable
18:16:12.096 INFO CollectMultipleMetricsSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
18:16:12.096 INFO CollectMultipleMetricsSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
18:16:12.096 INFO CollectMultipleMetricsSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
18:16:12.096 INFO CollectMultipleMetricsSpark - Start Date/Time: May 27, 2025 at 6:16:12 PM UTC
18:16:12.096 INFO CollectMultipleMetricsSpark - ------------------------------------------------------------
18:16:12.096 INFO CollectMultipleMetricsSpark - ------------------------------------------------------------
18:16:12.096 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
18:16:12.096 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
18:16:12.096 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
18:16:12.096 INFO CollectMultipleMetricsSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
18:16:12.096 INFO CollectMultipleMetricsSpark - Deflater: IntelDeflater
18:16:12.096 INFO CollectMultipleMetricsSpark - Inflater: IntelInflater
18:16:12.096 INFO CollectMultipleMetricsSpark - GCS max retries/reopens: 20
18:16:12.096 INFO CollectMultipleMetricsSpark - Requester pays: disabled
18:16:12.096 WARN CollectMultipleMetricsSpark -
?[1m?[31m !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Warning: CollectMultipleMetricsSpark is a BETA tool and is not yet ready for use in production
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!?[0m
18:16:12.096 INFO CollectMultipleMetricsSpark - Initializing engine
18:16:12.096 INFO CollectMultipleMetricsSpark - Done initializing engine
18:16:12.096 INFO CollectMultipleMetricsSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
18:16:12.099 INFO MemoryStore - Block broadcast_3416 stored as values in memory (estimated size 600.0 B, free 1918.2 MiB)
18:16:12.099 INFO MemoryStore - Block broadcast_3416_piece0 stored as bytes in memory (estimated size 211.0 B, free 1918.2 MiB)
18:16:12.099 INFO BlockManagerInfo - Added broadcast_3416_piece0 in memory on localhost:44275 (size: 211.0 B, free: 1919.6 MiB)
18:16:12.099 INFO SparkContext - Created broadcast 3416 from broadcast at CramSource.java:114
18:16:12.100 INFO MemoryStore - Block broadcast_3417 stored as values in memory (estimated size 306.3 KiB, free 1917.9 MiB)
18:16:12.111 INFO MemoryStore - Block broadcast_3417_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1917.9 MiB)
18:16:12.111 INFO BlockManagerInfo - Added broadcast_3417_piece0 in memory on localhost:44275 (size: 64.4 KiB, free: 1919.5 MiB)
18:16:12.111 INFO SparkContext - Created broadcast 3417 from newAPIHadoopFile at PathSplitSource.java:96
18:16:12.131 INFO MemoryStore - Block broadcast_3418 stored as values in memory (estimated size 600.0 B, free 1917.9 MiB)
18:16:12.131 INFO MemoryStore - Block broadcast_3418_piece0 stored as bytes in memory (estimated size 211.0 B, free 1917.9 MiB)
18:16:12.131 INFO BlockManagerInfo - Added broadcast_3418_piece0 in memory on localhost:44275 (size: 211.0 B, free: 1919.5 MiB)
18:16:12.132 INFO SparkContext - Created broadcast 3418 from broadcast at CramSource.java:114
18:16:12.132 INFO MemoryStore - Block broadcast_3419 stored as values in memory (estimated size 306.3 KiB, free 1917.6 MiB)
18:16:12.139 INFO MemoryStore - Block broadcast_3419_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1917.5 MiB)
18:16:12.139 INFO BlockManagerInfo - Added broadcast_3419_piece0 in memory on localhost:44275 (size: 64.4 KiB, free: 1919.5 MiB)
18:16:12.139 INFO SparkContext - Created broadcast 3419 from newAPIHadoopFile at PathSplitSource.java:96
18:16:12.152 INFO FileInputFormat - Total input files to process : 1
18:16:12.155 INFO SparkContext - Starting job: count at CollectMultipleMetricsSparkIntegrationTest.java:130
18:16:12.156 INFO DAGScheduler - Got job 894 (count at CollectMultipleMetricsSparkIntegrationTest.java:130) with 1 output partitions
18:16:12.156 INFO DAGScheduler - Final stage: ResultStage 2487 (count at CollectMultipleMetricsSparkIntegrationTest.java:130)
18:16:12.156 INFO DAGScheduler - Parents of final stage: List()
18:16:12.156 INFO DAGScheduler - Missing parents: List()
18:16:12.156 INFO DAGScheduler - Submitting ResultStage 2487 (MapPartitionsRDD[10267] at filter at CollectMultipleMetricsSpark.java:193), which has no missing parents
18:16:12.167 INFO MemoryStore - Block broadcast_3420 stored as values in memory (estimated size 330.5 KiB, free 1917.2 MiB)
18:16:12.168 INFO MemoryStore - Block broadcast_3420_piece0 stored as bytes in memory (estimated size 143.8 KiB, free 1917.0 MiB)
18:16:12.169 INFO BlockManagerInfo - Added broadcast_3420_piece0 in memory on localhost:44275 (size: 143.8 KiB, free: 1919.3 MiB)
18:16:12.169 INFO SparkContext - Created broadcast 3420 from broadcast at DAGScheduler.scala:1580
18:16:12.169 INFO DAGScheduler - Submitting 1 missing tasks from ResultStage 2487 (MapPartitionsRDD[10267] at filter at CollectMultipleMetricsSpark.java:193) (first 15 tasks are for partitions Vector(0))
18:16:12.169 INFO TaskSchedulerImpl - Adding task set 2487.0 with 1 tasks resource profile 0
18:16:12.169 INFO TaskSetManager - Starting task 0.0 in stage 2487.0 (TID 1918) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9773 bytes)
18:16:12.169 INFO Executor - Running task 0.0 in stage 2487.0 (TID 1918)
18:16:12.190 INFO NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/metrics/analysis/CollectInsertSizeMetrics/insert_size_metrics_test.cram:0+8617
18:16:12.194 INFO Executor - Finished task 0.0 in stage 2487.0 (TID 1918). 989 bytes result sent to driver
18:16:12.195 INFO TaskSetManager - Finished task 0.0 in stage 2487.0 (TID 1918) in 26 ms on localhost (executor driver) (1/1)
18:16:12.195 INFO TaskSchedulerImpl - Removed TaskSet 2487.0, whose tasks have all completed, from pool
18:16:12.195 INFO DAGScheduler - ResultStage 2487 (count at CollectMultipleMetricsSparkIntegrationTest.java:130) finished in 0.039 s
18:16:12.195 INFO DAGScheduler - Job 894 is finished. Cancelling potential speculative or zombie tasks for this job
18:16:12.195 INFO TaskSchedulerImpl - Killing all running tasks in stage 2487: Stage finished
18:16:12.195 INFO DAGScheduler - Job 894 finished: count at CollectMultipleMetricsSparkIntegrationTest.java:130, took 0.039578 s
18:16:12.195 INFO CollectMultipleMetricsSpark - Shutting down engine
[May 27, 2025 at 6:16:12 PM UTC] org.broadinstitute.hellbender.tools.spark.pipelines.metrics.CollectMultipleMetricsSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1432354816