Multiple platform build/check report for BioC 3.20 - CHECK results for HTSeqGenie on taishan

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo2	Linux (Ubuntu 24.04.1 LTS)	x86_64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4769
palomino8	Windows Server 2022 Datacenter	x64	4.4.2 (2024-10-31 ucrt) -- "Pile of Leaves"	4504
merida1	macOS 12.7.5 Monterey	x86_64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4527
kjohnson1	macOS 13.6.6 Ventura	arm64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4480
taishan	Linux (openEuler 24.03 LTS)	aarch64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4416
Click on any hostname to see more info about the system (e.g. compilers) () as reported by 'uname -p', except on Windows and Mac OS X*

CHECK results for HTSeqGenie on taishan

To the developers/maintainers of the HTSeqGenie package:
- Allow up to 24 hours (and sometimes 48 hours) for your latest push to git@git.bioconductor.org:packages/HTSeqGenie.git to reflect on this report. See Troubleshooting Build Report for more information.
- Use the following Renviron settings to reproduce errors and warnings.
- If 'R CMD check' started to fail recently on the Linux builder(s) over a missing dependency, add the missing dependency to 'Suggests:' in your DESCRIPTION file. See Renviron.bioc for more information.
- See Martin Grigorov's blog post for how to debug Linux ARM64 related issues on a x86_64 host.

raw results

Summary

Package: HTSeqGenie

Version: 4.36.0

Command: /home/biocbuild/R/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/R/R/site-library --no-vignettes --timings HTSeqGenie_4.36.0.tar.gz

StartedAt: 2025-03-04 07:25:03 -0000 (Tue, 04 Mar 2025)

EndedAt: 2025-03-04 07:38:21 -0000 (Tue, 04 Mar 2025)

EllapsedTime: 798.7 seconds

RetCode: 0

Status: OK

CheckDir: HTSeqGenie.Rcheck

Warnings: 0

Command output

##############################################################################
##############################################################################
###
### Running command:
###
###   /home/biocbuild/R/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/R/R/site-library --no-vignettes --timings HTSeqGenie_4.36.0.tar.gz
###
##############################################################################
##############################################################################


* using log directory ‘/home/biocbuild/bbs-3.20-bioc/meat/HTSeqGenie.Rcheck’
* using R version 4.4.2 (2024-10-31)
* using platform: aarch64-unknown-linux-gnu
* R was compiled by
    aarch64-unknown-linux-gnu-gcc (GCC) 14.2.0
    GNU Fortran (GCC) 12.3.1 (openEuler 12.3.1-36.oe2403)
* running under: openEuler 24.03 (LTS)
* using session charset: UTF-8
* using option ‘--no-vignettes’
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.36.0’
* checking package namespace information ... OK
* checking package dependencies ... OK
* checking if this is a source package ... OK
* checking if there is a namespace ... OK
* checking for hidden files and directories ... NOTE
Found the following hidden files and directories:
  .BBSoptions
These were most likely included in error. See section ‘Package
structure’ in the ‘Writing R Extensions’ manual.
* checking for portable file names ... OK
* checking for sufficient/correct file permissions ... OK
* checking whether package ‘HTSeqGenie’ can be installed ... OK
* checking installed package size ... OK
* checking package directory ... OK
* checking ‘build’ directory ... OK
* checking DESCRIPTION meta-information ... NOTE
Malformed Title field: should not end in a period.
* checking top-level files ... OK
* checking for left-over files ... OK
* checking index information ... OK
* checking package subdirectories ... OK
* checking code files for non-ASCII characters ... OK
* checking R files for syntax errors ... OK
* checking whether the package can be loaded ... OK
* checking whether the package can be loaded with stated dependencies ... OK
* checking whether the package can be unloaded cleanly ... OK
* checking whether the namespace can be loaded with stated dependencies ... OK
* checking whether the namespace can be unloaded cleanly ... OK
* checking loading without being on the library search path ... OK
* checking whether startup messages can be suppressed ... OK
* checking dependencies in R code ... NOTE
Unexported objects imported by ':::' calls:
  ‘ShortRead:::.set_omp_threads’ ‘gmapR:::..gsnap’ ‘gmapR:::GeneGenome’
  ‘gmapR:::checkPackageInstalled’ ‘gmapR:::getDefaultGmapGenomePath’
  ‘gmapR:::getGeneRoi’ ‘gmapR:::subsetRegion’ ‘parallel:::mckill’
  See the note in ?`:::` about the use of this operator.
* checking S3 generic/method consistency ... OK
* checking replacement functions ... OK
* checking foreign function calls ... NOTE
Foreign function call to a different package:
  .Call(ShortRead:::.set_omp_threads, ...)
See chapter ‘System and foreign language interfaces’ in the ‘Writing R
Extensions’ manual.
* checking R code for possible problems ... NOTE
.makePreprocessAlignPlots: no visible binding for global variable
  ‘data’
.plot.in.out.min.max.readlength: no visible global function definition
  for ‘median’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.lfqs’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.chunkid’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.subsampling_filter’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.max_nbchunks’
addHandler: no visible binding for '<<-' assignment to
  ‘logging.handlers’
addHandler: no visible binding for global variable ‘logging.handlers’
addHandler: no visible binding for '<<-' assignment to ‘logging.file’
buildAnyFastaGenome: no visible global function definition for ‘getSeq’
buildGenomicFeaturesFromTxDb: no visible global function definition for
  ‘gaps’
buildGenomicFeaturesFromTxDb: no visible global function definition for
  ‘ranges’
buildTP53FastaGenome: no visible global function definition for
  ‘getSeq’
buildTallyParam: no visible global function definition for ‘seqinfo’
computeCoverage: no visible global function definition for ‘resize’
computeCoverage: no visible global function definition for ‘coverage’
estimateCutoffs : <anonymous>: no visible binding for global variable
  ‘quantile’
getGenomeSegments: no visible global function definition for ‘seqinfo’
hashVariants: no visible global function definition for ‘ranges’
isAboveQualityThresh: no visible global function definition for ‘Views’
isAboveQualityThresh: no visible global function definition for
  ‘viewMeans’
listIterator.init: no visible binding for '<<-' assignment to
  ‘listIterator.n’
listIterator.init: no visible binding for '<<-' assignment to
  ‘listIterator.x’
logReset: no visible binding for '<<-' assignment to ‘logging.handlers’
logReset: no visible binding for '<<-' assignment to ‘logging.loglevel’
logReset: no visible binding for '<<-' assignment to ‘logging.file’
loglevel: no visible binding for global variable ‘logging.loglevel’
loglevel: no visible binding for global variable ‘logging.handlers’
processChunks : tracefun: no visible binding for global variable
  ‘sjobs’
processChunks : tracefun: no visible binding for global variable
  ‘chunkid’
setLevel: no visible binding for '<<-' assignment to ‘logging.loglevel’
statCountFeatures: no visible global function definition for ‘quantile’
truncateReads: no visible global function definition for ‘subseq’
vcfStat: no visible global function definition for ‘quantile’
writeToFile: no visible binding for global variable ‘logging.file’
Undefined global functions or variables:
  Views chunkid coverage data gaps getSeq logging.file logging.handlers
  logging.loglevel median quantile ranges resize seqinfo sjobs subseq
  viewMeans
Consider adding
  importFrom("stats", "median", "quantile")
  importFrom("utils", "data")
to your NAMESPACE file.
* checking Rd files ... NOTE
checkRd: (-1) calculateTargetLengths.Rd:17: Lost braces; missing escapes or markup?
    17 | Target length table and writes two files in {save_dir}/reports/images/TargetLenghts.[pdf|png]"
       |                                             ^
checkRd: (-1) initLog.Rd:18: Lost braces; missing escapes or markup?
    18 | Setup logging file in {save_dir}/progress.log
       |                       ^
* checking Rd metadata ... OK
* checking Rd cross-references ... OK
* checking for missing documentation entries ... OK
* checking for code/documentation mismatches ... OK
* checking Rd \usage sections ... NOTE
Documented arguments not in \usage in Rd file 'findVariantFile.Rd':
  ‘dir_path’

Documented arguments not in \usage in Rd file 'logdebug.Rd':
  ‘...’

Documented arguments not in \usage in Rd file 'logerror.Rd':
  ‘...’

Documented arguments not in \usage in Rd file 'loginfo.Rd':
  ‘...’

Documented arguments not in \usage in Rd file 'logwarn.Rd':
  ‘...’

Functions with \usage entries need to have the appropriate \alias
entries, and all their arguments documented.
The \usage entries must correspond to syntactically valid R code.
See chapter ‘Writing R documentation files’ in the ‘Writing R
Extensions’ manual.
* checking Rd contents ... OK
* checking for unstated dependencies in examples ... OK
* checking files in ‘vignettes’ ... OK
* checking examples ... OK
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
  Running ‘doRUnit.R’
 OK
* checking for unstated dependencies in vignettes ... OK
* checking package vignettes ... OK
* checking running R code from vignettes ... SKIPPED
* checking re-building of vignette outputs ... SKIPPED
* checking PDF version of manual ... OK
* DONE

Status: 7 NOTEs
See
  ‘/home/biocbuild/bbs-3.20-bioc/meat/HTSeqGenie.Rcheck/00check.log’
for details.

Installation output

HTSeqGenie.Rcheck/00install.out

##############################################################################
##############################################################################
###
### Running command:
###
###   /home/biocbuild/R/R/bin/R CMD INSTALL HTSeqGenie
###
##############################################################################
##############################################################################


* installing to library ‘/home/biocbuild/R/R-4.4.2/site-library’
* installing *source* package ‘HTSeqGenie’ ...
** using staged installation
** R
** inst
** byte-compile and prepare package for lazy loading
** help
*** installing help indices
** building package indices
** installing vignettes
** testing if installed package can be loaded from temporary location
** testing if installed package can be loaded from final location
** testing if installed package keeps a record of temporary installation path
* DONE (HTSeqGenie)

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R version 4.4.2 (2024-10-31) -- "Pile of Leaves"
Copyright (C) 2024 The R Foundation for Statistical Computing
Platform: aarch64-unknown-linux-gnu

R is free software and comes with ABSOLUTELY NO WARRANTY.
You are welcome to redistribute it under certain conditions.
Type 'license()' or 'licence()' for distribution details.

R is a collaborative project with many contributors.
Type 'contributors()' for more information and
'citation()' on how to cite R or R packages in publications.

Type 'demo()' for some demos, 'help()' for on-line help, or
'help.start()' for an HTML browser interface to help.
Type 'q()' to quit R.

> library("HTSeqGenie")
Loading required package: gmapR
Loading required package: GenomeInfoDb
Loading required package: BiocGenerics

Attaching package: 'BiocGenerics'

The following objects are masked from 'package:stats':

    IQR, mad, sd, var, xtabs

The following objects are masked from 'package:base':

    Filter, Find, Map, Position, Reduce, anyDuplicated, aperm, append,
    as.data.frame, basename, cbind, colnames, dirname, do.call,
    duplicated, eval, evalq, get, grep, grepl, intersect, is.unsorted,
    lapply, mapply, match, mget, order, paste, pmax, pmax.int, pmin,
    pmin.int, rank, rbind, rownames, sapply, saveRDS, setdiff, table,
    tapply, union, unique, unsplit, which.max, which.min

Loading required package: S4Vectors
Loading required package: stats4

Attaching package: 'S4Vectors'

The following object is masked from 'package:utils':

    findMatches

The following objects are masked from 'package:base':

    I, expand.grid, unname

Loading required package: IRanges
Loading required package: GenomicRanges
Loading required package: Rsamtools
Loading required package: Biostrings
Loading required package: XVector

Attaching package: 'Biostrings'

The following object is masked from 'package:base':

    strsplit

Loading required package: ShortRead
Loading required package: BiocParallel
Loading required package: GenomicAlignments
Loading required package: SummarizedExperiment
Loading required package: MatrixGenerics
Loading required package: matrixStats

Attaching package: 'MatrixGenerics'

The following objects are masked from 'package:matrixStats':

    colAlls, colAnyNAs, colAnys, colAvgsPerRowSet, colCollapse,
    colCounts, colCummaxs, colCummins, colCumprods, colCumsums,
    colDiffs, colIQRDiffs, colIQRs, colLogSumExps, colMadDiffs,
    colMads, colMaxs, colMeans2, colMedians, colMins, colOrderStats,
    colProds, colQuantiles, colRanges, colRanks, colSdDiffs, colSds,
    colSums2, colTabulates, colVarDiffs, colVars, colWeightedMads,
    colWeightedMeans, colWeightedMedians, colWeightedSds,
    colWeightedVars, rowAlls, rowAnyNAs, rowAnys, rowAvgsPerColSet,
    rowCollapse, rowCounts, rowCummaxs, rowCummins, rowCumprods,
    rowCumsums, rowDiffs, rowIQRDiffs, rowIQRs, rowLogSumExps,
    rowMadDiffs, rowMads, rowMaxs, rowMeans2, rowMedians, rowMins,
    rowOrderStats, rowProds, rowQuantiles, rowRanges, rowRanks,
    rowSdDiffs, rowSds, rowSums2, rowTabulates, rowVarDiffs, rowVars,
    rowWeightedMads, rowWeightedMeans, rowWeightedMedians,
    rowWeightedSds, rowWeightedVars

Loading required package: Biobase
Welcome to Bioconductor

    Vignettes contain introductory material; view with
    'browseVignettes()'. To cite Bioconductor, see
    'citation("Biobase")', and for packages 'citation("pkgname")'.


Attaching package: 'Biobase'

The following object is masked from 'package:MatrixGenerics':

    rowMedians

The following objects are masked from 'package:matrixStats':

    anyMissing, rowMedians

Loading required package: VariantAnnotation

Attaching package: 'VariantAnnotation'

The following object is masked from 'package:base':

    tabulate

> 
> source(getPackageFile("unitTests/runTests.R"))
Loading required package: GenomicFeatures
Loading required package: AnnotationDbi
did not source anything in dirname= ./R 


Executing test function test.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:31:36.291771 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-04 07:31:36.300357 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:31:36.305904 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-04 07:31:36.308525 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:31:38.929062 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:31:38.930913 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/chunks/chunk_000001/logs/progress.log
2025-03-04 07:31:41.738106 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2025-03-04 07:31:41.739995 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/chunks/chunk_000002/logs/progress.log
2025-03-04 07:31:44.550557 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2025-03-04 07:31:44.552325 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/chunks/chunk_000003/logs/progress.log
2025-03-04 07:31:47.382177 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2025-03-04 07:31:47.420351 DEBUG::tools.R/processChunks: done
2025-03-04 07:31:47.424941 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-04 07:31:47.427788 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/results/test_pe.adapter_contaminated_1.RData
2025-03-04 07:31:47.431291 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-04 07:31:47.433554 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/results/test_pe.adapter_contaminated_2.RData
2025-03-04 07:31:47.445122 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-04 07:31:47.447994 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/results/test_pe.summary_preprocess.tab
2025-03-04 07:31:47.452116 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/bams/processed.aligner_input_1.fastq ...
2025-03-04 07:31:47.458305 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/bams/processed.aligner_input_2.fastq ...
2025-03-04 07:31:47.46341 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/reports/shortReadReport_1 ...
2025-03-04 07:31:49.312644 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/reports/shortReadReport_2 ...
2025-03-04 07:31:50.783871 INFO::preprocessReads.R/preprocessReads: done
2025-03-04 07:31:50.835274 INFO::alignReads.R/alignReads: starting alignment...
2025-03-04 07:31:50.841165 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:31:53.24161 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:31:53.243653 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/chunks/chunk_000001/logs/progress.log
2025-03-04 07:31:56.356056 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.052 minutes
2025-03-04 07:31:56.365662 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-04 07:31:59.00082 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-03-04 07:31:59.002901 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-04 07:32:01.734043 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-03-04 07:32:01.737648 DEBUG::tools.R/processChunks: done
2025-03-04 07:32:01.739491 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-04 07:32:02.044828 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-04 07:32:02.055923 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/results/test_pe.summary_alignment.tab
2025-03-04 07:32:02.065845 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/results/test_pe.summary_analyzed_bamstats.tab
2025-03-04 07:32:02.068066 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-04 07:32:02.345294 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.2a30562fe8d4d8/results/test_pe.summary_target_lengths.tab
2025-03-04 07:32:02.403462 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-04 07:32:02.404777 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:32:02.696095 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-04 07:32:02.699285 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:32:02.769442 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-03-04 07:32:02.775697 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:32:02.77972 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-04 07:32:02.782113 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:32:05.248808 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:32:05.250805 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/chunks/chunk_000001/logs/progress.log
2025-03-04 07:32:08.023091 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-03-04 07:32:08.02507 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/chunks/chunk_000002/logs/progress.log
2025-03-04 07:32:10.758462 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2025-03-04 07:32:10.76034 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/chunks/chunk_000003/logs/progress.log
2025-03-04 07:32:13.627432 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2025-03-04 07:32:13.629258 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/chunks/chunk_000004/logs/progress.log
2025-03-04 07:32:16.364934 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.046 minutes
2025-03-04 07:32:16.403074 DEBUG::tools.R/processChunks: done
2025-03-04 07:32:16.407484 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-04 07:32:16.410594 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/results/test_pe.adapter_contaminated_1.RData
2025-03-04 07:32:16.414443 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-04 07:32:16.416818 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/results/test_pe.adapter_contaminated_2.RData
2025-03-04 07:32:16.429946 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2 highqual_reads=1 adapter_contam=0 read_length=75 rRNA_contam_reads=0 processed_reads=1 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-04 07:32:16.43278 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/results/test_pe.summary_preprocess.tab
2025-03-04 07:32:16.437328 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/bams/processed.aligner_input_1.fastq ...
2025-03-04 07:32:16.443892 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/bams/processed.aligner_input_2.fastq ...
2025-03-04 07:32:16.449192 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/reports/shortReadReport_1 ...
2025-03-04 07:32:18.215206 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.alignReads.sparsechunks.2a3056578cc068/reports/shortReadReport_2 ...
2025-03-04 07:32:19.664802 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:32:19.865348 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-03-04 07:32:19.871065 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -D /home/biocbuild/.local/share/gmap -t 1 -d TP53_demo_3.2.2 --quality-protocol=illumina  -A sam --read-group-id=test_se -m 0 --split-output /home/biocbuild/tmp/RtmpErxfvw/test.alignReadsOneSingleEnd.2a30565345495e/bams/test.alignReads /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-03-04 07:32:19.990301 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-03-04 07:32:20.119265 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReadsOneSingleEnd.2a30565345495e/results/test.alignReads.summary_alignment.tab
2025-03-04 07:32:20.176219 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.alignReadsOneSingleEnd.2a30565345495e/results/test.alignReads.summary_analyzed_bamstats.tab
2025-03-04 07:32:20.178311 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.001 0.003 0.004
Error in DEACTIVATED("Skipped annotateVariants() test") : 
  Skipped annotateVariants() test
In addition: There were 11 warnings (use warnings() to see them)
 done successfully.



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:32:20.578917 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.genotype.2a305661112f93/results/test_pe.coverage.RData
2025-03-04 07:32:20.581202 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.genotype.2a305661112f93/results/test_pe.coverage.bw
2025-03-04 07:32:20.737811 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.genotype.2a305661112f93/results/test_pe.summary_coverage.tab
2025-03-04 07:32:20.740145 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-04 07:32:32.302029 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-04 07:32:32.424416 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-04 07:32:32.449193 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-04 07:32:32.451222 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.genotype.2a305661112f93/results/test_pe.raw_variants.RData
2025-03-04 07:32:32.454154 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.genotype.2a305661112f93/results/test_pe.filtered_variants.RData
2025-03-04 07:32:32.455941 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-04 07:32:32.457542 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-04 07:32:33.000091 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-04 07:32:33.001661 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-03-04 07:33:56.792593 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-04 07:33:57.434239 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-04 07:33:57.435674 INFO::analyzeVariants.R/.callGenotypes: done
[W::bcf_hdr_check_sanity] PL should be declared as Number=G
 done successfully.



Executing test function test.wrap.callVariants  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:33:58.050925 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-04 07:34:09.912489 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-04 07:34:10.032059 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-04 07:34:10.056461 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-04 07:34:10.058372 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.wrap.callVariants.2a305622fd4f20/results/test_pe.raw_variants.RData
2025-03-04 07:34:10.062991 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.wrap.callVariants.2a305622fd4f20/results/test_pe.filtered_variants.RData
2025-03-04 07:34:10.065169 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:34:10.264017 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-04 07:34:22.041859 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-04 07:34:22.12646 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-04 07:34:22.151256 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-04 07:34:22.153209 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.wrap.callVariants.filters.2a30563e10ad64/results/test_pe.raw_variants.RData
2025-03-04 07:34:22.156231 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.wrap.callVariants.filters.2a30563e10ad64/results/test_pe.filtered_variants.RData
2025-03-04 07:34:22.158098 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-04 07:34:22.160057 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-04 07:34:33.760037 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-04 07:34:33.817048 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-04 07:34:33.841679 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-04 07:34:33.843604 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.wrap.callVariants.filters.2a30563e10ad64/results/test_pe.raw_variants.RData
2025-03-04 07:34:33.846868 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.wrap.callVariants.filters.2a30563e10ad64/results/test_pe.filtered_variants.RData
2025-03-04 07:34:33.849429 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:34:34.179763 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-04 07:34:34.1818 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-03-04 07:34:37.264872 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-04 07:34:37.376303 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-04 07:34:37.400344 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-04 07:34:37.402339 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.wrap.callVariants.which.2a30564c06e1af/results/test_pe.raw_variants.RData
2025-03-04 07:34:37.404612 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.wrap.callVariants.which.2a30564c06e1af/results/test_pe.filtered_variants.RData
2025-03-04 07:34:37.406458 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:34:37.608362 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-04 07:34:37.610251 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:34:39.145584 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-04 07:34:39.423342 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.isFirstFragment  ...  done successfully.



Executing test function test.buildCountsGRangesList  ...   403 genes were dropped because they have exons located on both strands
  of the same reference sequence or on more than one reference sequence,
  so cannot be represented by a single genomic range.
  Use 'single.strand.genes.only=FALSE' to get all the genes in a
  GRangesList object, or use suppressMessages() to suppress this message.
 done successfully.



Executing test function test.generateSingleGeneDERs  ...  done successfully.



Executing test function test.computeCoverage  ...  done successfully.



Executing test function test.isSparse  ...  done successfully.



Executing test function test.mergeCoverage  ... 2025-03-04 07:35:41.369007 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/kxntrszy/merged/results/bla.coverage.RData
2025-03-04 07:35:41.372295 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpErxfvw/kxntrszy/merged/results/bla.coverage.bw
2025-03-04 07:35:41.451633 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/kxntrszy/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-03-04 07:35:42.403712 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/ixchojma/merged/results/bla.coverage.RData
2025-03-04 07:35:42.405631 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpErxfvw/ixchojma/merged/results/bla.coverage.bw
2025-03-04 07:35:42.419987 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/ixchojma/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.findTemplate  ...  done successfully.



Executing test function test.checkConfig  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.checkConfig.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.getConfig  ...  done successfully.



Executing test function test.loadConfig  ...  done successfully.



Executing test function test.parseDCF  ...  done successfully.



Executing test function test.updateConfig  ...  done successfully.



Executing test function test.getAdapterSeqs  ...  done successfully.



Executing test function test.isAdapter  ...  done successfully.



Executing test function test.isAdapter3.primeEnd  ...  done successfully.



Executing test function test.detectRRNA  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:35:43.920932 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-03-04 07:35:43.922417 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpErxfvw/test.detectRRNA.2a3056684e7a0f/bams/rRNA_contam/input1.fastq
2025-03-04 07:35:43.926765 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /home/biocbuild/tmp/RtmpErxfvw/test.detectRRNA.2a3056684e7a0f/bams/rRNA_contam/test_se /home/biocbuild/tmp/RtmpErxfvw/test.detectRRNA.2a3056684e7a0f/bams/rRNA_contam/input1.fastq 2>&1
2025-03-04 07:35:44.05039 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-03-04 07:35:44.051689 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:35:44.246871 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-03-04 07:35:44.248251 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpErxfvw/test.detectRRNA.paired_end.2a30567e5fecf1/bams/rRNA_contam/input1.fastq
2025-03-04 07:35:44.250457 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpErxfvw/test.detectRRNA.paired_end.2a30567e5fecf1/bams/rRNA_contam/input2.fastq
2025-03-04 07:35:44.253706 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /home/biocbuild/tmp/RtmpErxfvw/test.detectRRNA.paired_end.2a30567e5fecf1/bams/rRNA_contam/test_pe /home/biocbuild/tmp/RtmpErxfvw/test.detectRRNA.paired_end.2a30567e5fecf1/bams/rRNA_contam/input1.fastq -a paired /home/biocbuild/tmp/RtmpErxfvw/test.detectRRNA.paired_end.2a30567e5fecf1/bams/rRNA_contam/input2.fastq 2>&1
2025-03-04 07:35:44.510328 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-03-04 07:35:44.511755 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-03-04 07:35:44.540516 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /home/biocbuild/tmp/RtmpErxfvw/test_get_rRNA_idslomnzasj/test_pe /home/biocbuild/tmp/RtmpErxfvw/test_get_rRNA_idslomnzasj/1.fastq -a paired /home/biocbuild/tmp/RtmpErxfvw/test_get_rRNA_idslomnzasj/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-03-04 07:35:44.823187 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /home/biocbuild/tmp/RtmpErxfvw/test_get_rRNAIds_randomjzahorkl/test_pe /home/biocbuild/tmp/RtmpErxfvw/test_get_rRNAIds_randomjzahorkl/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-03-04 07:35:44.958627 INFO::filterQuality.R/filterQuality: filterByLength...
2025-03-04 07:35:44.96058 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-03-04 07:35:44.96201 INFO::filterQuality.R/filterByLength: done
2025-03-04 07:35:45.027514 INFO::filterQuality.R/filterQuality: filterByLength...
2025-03-04 07:35:45.028764 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-03-04 07:35:45.030007 INFO::filterQuality.R/filterByLength: done
 done successfully.



Executing test function test.isAboveQualityThresh  ...  done successfully.



Executing test function test.trimTailsByQuality  ... 2025-03-04 07:35:45.101361 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-04 07:35:45.113822 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-04 07:35:45.115295 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-04 07:35:45.121577 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-04 07:35:45.123017 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-04 07:35:45.129344 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-04 07:35:45.130785 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-04 07:35:45.137084 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



Executing test function test.callVariantsGATK  ... Timing stopped at: 0 0 0.001
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") : 
  callVariantsGATK() tests need gatk.path option set
In addition: There were 50 or more warnings (use warnings() to see the first 50)
 done successfully.



Executing test function test.callVariantsGATK.withFiltering  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") : 
  callVariantsGATK() tests need gatk.path option set
 done successfully.



Executing test function test.checkGATKJar  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") : 
  checkGATKJar() test needs gatk.path option set
 done successfully.



Executing test function test.excludeVariantsByRegion  ...  done successfully.



Executing test function test.gatk  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("gatk() tests need gatk.path option set") : 
  gatk() tests need gatk.path option set
 done successfully.



Executing test function test.realignIndels  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("test.realignIndels() tests need gatk.path option set") : 
  test.realignIndels() tests need gatk.path option set
 done successfully.



Executing test function test.realignIndelsGATK  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") : 
  realignIndelsGATK() tests need gatk.path option set
 done successfully.



Executing test function test.realignIndelsGATK.parallel  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") : 
  realignIndelsGATK() tests need gatk.path option set
 done successfully.



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:35:45.524624 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:35:45.527884 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.pefq.subsample  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:35:45.710408 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:35:45.805369 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-04 07:35:45.8095 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:35:45.812947 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.segz  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:35:46.075724 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/reads.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.getReads.truncated  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:35:46.254478 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/truncated.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:35:46.418716 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:35:46.471848 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-04 07:35:46.475236 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:35:46.478427 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:35:46.701401 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:35:46.755378 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-04 07:35:46.758847 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:35:46.762134 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.createTmpDir  ...  done successfully.



Executing test function test.detectQualityInFASTQFile  ...  done successfully.



Executing test function test.getObjectFilename  ...  done successfully.



Executing test function test.safeUnlink  ...  done successfully.



Executing test function test.writeAudit  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:35:47.585372 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-04 07:35:47.59197 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:35:47.596518 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-04 07:35:47.599446 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:35:50.160484 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:35:50.162532 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000001/logs/progress.log
2025-03-04 07:35:52.832182 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-03-04 07:35:52.834178 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000002/logs/progress.log
2025-03-04 07:35:55.515373 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-03-04 07:35:55.517296 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000003/logs/progress.log
2025-03-04 07:35:58.207561 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-03-04 07:35:58.259008 DEBUG::tools.R/processChunks: done
2025-03-04 07:35:58.262723 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-04 07:35:58.265146 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.adapter_contaminated_1.RData
2025-03-04 07:35:58.268108 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-04 07:35:58.27039 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.adapter_contaminated_2.RData
2025-03-04 07:35:58.281388 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-04 07:35:58.284047 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.summary_preprocess.tab
2025-03-04 07:35:58.287681 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/bams/processed.aligner_input_1.fastq ...
2025-03-04 07:35:58.293978 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/bams/processed.aligner_input_2.fastq ...
2025-03-04 07:35:58.299116 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/reports/shortReadReport_1 ...
2025-03-04 07:36:00.119485 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/reports/shortReadReport_2 ...
2025-03-04 07:36:01.637381 INFO::preprocessReads.R/preprocessReads: done
2025-03-04 07:36:01.709058 INFO::alignReads.R/alignReads: starting alignment...
2025-03-04 07:36:01.713914 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:36:04.362585 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:36:04.364674 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000001/logs/progress.log
2025-03-04 07:36:06.916945 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-03-04 07:36:06.919099 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-04 07:36:09.492695 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-03-04 07:36:09.494775 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-04 07:36:12.141457 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-03-04 07:36:12.144605 DEBUG::tools.R/processChunks: done
2025-03-04 07:36:12.146495 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-04 07:36:12.431719 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-04 07:36:12.441852 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.summary_alignment.tab
2025-03-04 07:36:12.451319 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.summary_analyzed_bamstats.tab
2025-03-04 07:36:12.453739 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-04 07:36:12.705188 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.summary_target_lengths.tab
2025-03-04 07:36:12.765567 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-04 07:36:12.767017 INFO::alignReads.R/alignReads: done
2025-03-04 07:36:12.844035 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-03-04 07:36:12.864714 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:36:15.522058 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:36:15.524275 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000001/logs/progress.log
2025-03-04 07:36:18.094089 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-03-04 07:36:18.096239 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000002/logs/progress.log
2025-03-04 07:36:20.658251 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-03-04 07:36:20.660237 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000003/logs/progress.log
2025-03-04 07:36:23.220879 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-03-04 07:36:23.224078 DEBUG::tools.R/processChunks: done
2025-03-04 07:36:23.226216 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-03-04 07:36:23.243477 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.counts_exon.tab
2025-03-04 07:36:23.257802 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.counts_exon_disjoint.tab
2025-03-04 07:36:23.267012 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.counts_gene.tab
2025-03-04 07:36:23.274429 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.counts_gene_coding.tab
2025-03-04 07:36:23.281684 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.counts_gene_exonic.tab
2025-03-04 07:36:23.289183 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.counts_intergenic.tab
2025-03-04 07:36:23.301297 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.counts_intron.tab
2025-03-04 07:36:23.305029 INFO::countGenomicFeatures.R/mergeCounts: done
2025-03-04 07:36:23.313001 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.summary_counts.tab
2025-03-04 07:36:23.315396 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-03-04 07:36:23.671911 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-03-04 07:36:23.673397 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-03-04 07:36:23.760599 INFO::coverage.R/calculateCoverage: starting...
2025-03-04 07:36:23.765265 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:36:26.431087 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:36:26.433233 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000001/logs/progress.log
2025-03-04 07:36:28.624552 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2025-03-04 07:36:28.626611 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000002/logs/progress.log
2025-03-04 07:36:30.820854 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2025-03-04 07:36:30.823109 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/chunks/chunk_000003/logs/progress.log
2025-03-04 07:36:33.009424 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.036 minutes
2025-03-04 07:36:33.012617 DEBUG::tools.R/processChunks: done
2025-03-04 07:36:34.501508 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.coverage.RData
2025-03-04 07:36:34.503603 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.coverage.bw
2025-03-04 07:36:34.520039 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.summary_coverage.tab
2025-03-04 07:36:34.522032 INFO::coverage.R/calculateCoverage: done
2025-03-04 07:36:34.524238 INFO::analyzeVariants/analyzeVariants: starting ...
2025-03-04 07:36:34.607348 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-04 07:36:37.710834 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-04 07:36:37.824777 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-04 07:36:37.850397 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-04 07:36:37.852299 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.raw_variants.RData
2025-03-04 07:36:37.85472 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.filtered_variants.RData
2025-03-04 07:36:37.856669 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-04 07:36:37.85836 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-04 07:36:38.203318 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-04 07:36:38.35648 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/results/test_pe.summary_variants.tab
2025-03-04 07:36:38.359276 INFO::analyzeVariants/analyzeVariants: done
2025-03-04 07:36:38.363635 INFO::Pipeline run successful.
2025-03-04 07:36:38.543246 INFO::mergeLanes.R/doMergeLanes: starting...
2025-03-04 07:36:38.54907 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-04 07:36:38.552404 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.adapter_contaminated_1.RData
2025-03-04 07:36:38.55666 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-04 07:36:38.559841 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.adapter_contaminated_2.RData
2025-03-04 07:36:38.575861 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-04 07:36:38.579191 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.summary_preprocess.tab
2025-03-04 07:36:38.582317 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-04 07:36:38.917766 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-04 07:36:38.926988 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.summary_alignment.tab
2025-03-04 07:36:38.93777 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.summary_analyzed_bamstats.tab
2025-03-04 07:36:38.940502 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-04 07:36:39.207272 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.summary_target_lengths.tab
2025-03-04 07:36:39.271834 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-04 07:36:39.314571 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-03-04 07:36:39.337438 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.counts_exon.tab
2025-03-04 07:36:39.351934 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.counts_exon_disjoint.tab
2025-03-04 07:36:39.361028 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.counts_gene.tab
2025-03-04 07:36:39.368521 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.counts_gene_coding.tab
2025-03-04 07:36:39.376027 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.counts_gene_exonic.tab
2025-03-04 07:36:39.383619 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.counts_intergenic.tab
2025-03-04 07:36:39.39851 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.counts_intron.tab
2025-03-04 07:36:39.40245 INFO::countGenomicFeatures.R/mergeCounts: done
2025-03-04 07:36:39.411298 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.summary_counts.tab
2025-03-04 07:36:39.413924 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-03-04 07:36:39.700361 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-03-04 07:36:41.529961 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.coverage.RData
2025-03-04 07:36:41.533391 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.coverage.bw
2025-03-04 07:36:41.550115 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.summary_coverage.tab
2025-03-04 07:36:41.590081 INFO::analyzeVariants/analyzeVariants: starting ...
2025-03-04 07:36:41.670581 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-04 07:36:44.762859 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-04 07:36:44.883636 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-04 07:36:44.911248 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-04 07:36:44.91341 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.raw_variants.RData
2025-03-04 07:36:44.916009 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.filtered_variants.RData
2025-03-04 07:36:44.918155 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-04 07:36:44.91985 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-04 07:36:45.247215 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-04 07:36:45.388997 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.mergeLanes.2a30562d483203/merged/results/merged.summary_variants.tab
2025-03-04 07:36:45.391534 INFO::analyzeVariants/analyzeVariants: done
2025-03-04 07:36:45.394582 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("Skipped markDuplicates() test") : 
  Skipped markDuplicates() test
In addition: There were 28 warnings (use warnings() to see them)
 done successfully.



Executing test function test.markDuplicates_w_outfile  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("Skipped markDuplicates() test") : 
  Skipped markDuplicates() test
 done successfully.



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:36:45.665079 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-04 07:36:45.683875 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:36:45.69719 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-04 07:36:45.699858 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:36:48.383971 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:36:48.385958 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.2a30564eea03ff/chunks/chunk_000001/logs/progress.log
2025-03-04 07:36:51.091016 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-03-04 07:36:51.140869 DEBUG::tools.R/processChunks: done
2025-03-04 07:36:51.143736 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-04 07:36:51.145852 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.2a30564eea03ff/results/test_pe.adapter_contaminated_1.RData
2025-03-04 07:36:51.14809 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-04 07:36:51.150075 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.2a30564eea03ff/results/test_pe.adapter_contaminated_2.RData
2025-03-04 07:36:51.15823 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-04 07:36:51.160713 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.2a30564eea03ff/results/test_pe.summary_preprocess.tab
2025-03-04 07:36:51.163648 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.2a30564eea03ff/bams/processed.aligner_input_1.fastq ...
2025-03-04 07:36:51.169269 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.2a30564eea03ff/bams/processed.aligner_input_2.fastq ...
2025-03-04 07:36:51.17448 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.2a30564eea03ff/reports/shortReadReport_1 ...
2025-03-04 07:36:53.025203 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.2a30564eea03ff/reports/shortReadReport_2 ...
2025-03-04 07:36:54.48858 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:36:54.82063 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-04 07:36:54.828994 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:36:54.835192 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-04 07:36:54.838739 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:36:57.646324 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:36:57.648309 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/chunks/chunk_000001/logs/progress.log
2025-03-04 07:37:00.37534 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-03-04 07:37:00.37745 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/chunks/chunk_000002/logs/progress.log
2025-03-04 07:37:03.10317 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-03-04 07:37:03.105061 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/chunks/chunk_000003/logs/progress.log
2025-03-04 07:37:05.824694 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-03-04 07:37:05.87296 DEBUG::tools.R/processChunks: done
2025-03-04 07:37:05.87644 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-04 07:37:05.878665 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/results/test_pe.adapter_contaminated_1.RData
2025-03-04 07:37:05.881616 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-04 07:37:05.883672 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/results/test_pe.adapter_contaminated_2.RData
2025-03-04 07:37:05.89427 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-04 07:37:05.896918 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/results/test_pe.summary_preprocess.tab
2025-03-04 07:37:05.900422 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/bams/processed.aligner_input_1.fastq ...
2025-03-04 07:37:05.906825 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/bams/processed.aligner_input_2.fastq ...
2025-03-04 07:37:05.912025 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/reports/shortReadReport_1 ...
2025-03-04 07:37:07.698621 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads.minichunks.2a305676722cd8/reports/shortReadReport_2 ...
2025-03-04 07:37:09.126483 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:37:09.434856 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-04 07:37:09.453907 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-04 07:37:09.457073 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:37:12.679585 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:37:12.681773 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads_single_end.2a305672f82d41/chunks/chunk_000001/logs/progress.log
2025-03-04 07:37:15.094506 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2025-03-04 07:37:15.137303 DEBUG::tools.R/processChunks: done
2025-03-04 07:37:15.140815 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-04 07:37:15.143526 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads_single_end.2a305672f82d41/results/test_se.adapter_contaminated_1.RData
2025-03-04 07:37:15.152097 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-04 07:37:15.154561 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads_single_end.2a305672f82d41/results/test_se.summary_preprocess.tab
2025-03-04 07:37:15.157274 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads_single_end.2a305672f82d41/bams/processed.aligner_input_1.fastq ...
2025-03-04 07:37:15.163178 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpErxfvw/test.preprocessReads_single_end.2a305672f82d41/reports/shortReadReport_1 ...
2025-03-04 07:37:16.95193 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.readRNASeqEnds  ...  done successfully.



Executing test function test.readRNASeqEnds.dupmark  ...  done successfully.



Executing test function test.how_many  ...  done successfully.



Executing test function test.plotDF  ...  done successfully.



Executing test function test.relativeBarPlot  ...  done successfully.



Executing test function test.runPipeline  ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:37:17.659106 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-04 07:37:17.677553 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2025-03-04 07:37:17.696626 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2025-03-04 07:37:17.6996 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:37:20.531375 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:37:20.533281 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-03-04 07:37:23.454581 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2025-03-04 07:37:23.514375 DEBUG::tools.R/processChunks: done
2025-03-04 07:37:23.51729 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-04 07:37:23.519269 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-03-04 07:37:23.521412 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-04 07:37:23.523252 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-03-04 07:37:23.531293 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2500 highqual_reads=2500 adapter_contam=0 read_length=100 rRNA_contam_reads=0 processed_reads=2500 input_min_read_length=100 input_max_read_length=100 processed_min_read_length=71 processed_max_read_length=100
2025-03-04 07:37:23.533751 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-03-04 07:37:23.536482 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-03-04 07:37:23.542475 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-03-04 07:37:23.548112 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-03-04 07:37:25.623411 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2025-03-04 07:37:27.341877 INFO::preprocessReads.R/preprocessReads: done
2025-03-04 07:37:27.418251 INFO::alignReads.R/alignReads: starting alignment...
2025-03-04 07:37:27.4224 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:37:30.036172 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:37:30.038273 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:1206:17367:135118" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:1304:1838:53573" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:2303:2956:116587" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "M" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:1206:20028:108227" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:1207:19518:143960" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:2207:4065:173048" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-04 07:37:35.452025 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.09 minutes
2025-03-04 07:37:35.455403 DEBUG::tools.R/processChunks: done
2025-03-04 07:37:35.457387 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2025-03-04 07:37:35.493155 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-04 07:37:35.501561 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2025-03-04 07:37:35.509112 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2025-03-04 07:37:35.511907 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-04 07:37:35.707126 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2025-03-04 07:37:35.769356 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-04 07:37:35.770784 INFO::alignReads.R/alignReads: done
2025-03-04 07:37:35.849244 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-03-04 07:37:35.869001 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:37:38.67753 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:37:38.679754 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-03-04 07:37:41.273981 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-03-04 07:37:41.277064 DEBUG::tools.R/processChunks: done
2025-03-04 07:37:41.279048 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-03-04 07:37:41.290362 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2025-03-04 07:37:41.299934 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2025-03-04 07:37:41.307021 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2025-03-04 07:37:41.311941 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2025-03-04 07:37:41.316863 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2025-03-04 07:37:41.321732 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2025-03-04 07:37:41.329175 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2025-03-04 07:37:41.333007 INFO::countGenomicFeatures.R/mergeCounts: done
2025-03-04 07:37:41.337778 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2025-03-04 07:37:41.340012 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-03-04 07:37:41.610442 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-03-04 07:37:41.611601 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-03-04 07:37:41.689959 INFO::coverage.R/calculateCoverage: starting...
2025-03-04 07:37:41.694129 DEBUG::tools.R/processChunks: starting...
2025-03-04 07:37:44.370442 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-04 07:37:44.372881 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-03-04 07:37:46.699892 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2025-03-04 07:37:46.703099 DEBUG::tools.R/processChunks: done
2025-03-04 07:37:48.106721 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2025-03-04 07:37:48.10873 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2025-03-04 07:37:48.18825 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2025-03-04 07:37:48.190093 INFO::coverage.R/calculateCoverage: done
2025-03-04 07:37:48.191853 INFO::analyzeVariants/analyzeVariants: starting ...
2025-03-04 07:37:48.269906 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-04 07:38:00.225681 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-04 07:38:00.333959 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-04 07:38:00.357233 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-04 07:38:00.359084 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2025-03-04 07:38:00.362061 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2025-03-04 07:38:00.363834 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-04 07:38:00.365212 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-04 07:38:00.67173 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-04 07:38:00.808076 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2025-03-04 07:38:00.810754 INFO::analyzeVariants/analyzeVariants: done
2025-03-04 07:38:00.816084 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpErxfvw/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-03-04 07:38:01.125442 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpErxfvw/test.calcTargetLengths.2a30561e615486/results/test_pe.summary_target_lengths.tab
 done successfully.



Executing test function test.sclapply  ...  done successfully.



Executing test function test.tryKeepTraceback  ...  done successfully.



Executing test function test.truncateReads  ...  done successfully.



Executing test function test.truncateReads.trim5  ...  done successfully.

RUNIT TEST PROTOCOL -- Tue Mar  4 07:38:15 2025 
*********************************************** 
Number of test functions: 61 
Number of deactivated test functions: 10 
Number of errors: 0 
Number of failures: 0 

 
1 Test Suite : 
HTSeqGenie unit testing - 61 test functions, 0 errors, 0 failures



Details 
*************************** 
Test Suite: HTSeqGenie unit testing 
Test function regexp: ^test.+ 
Test file regexp: ^runit.+\.[rR]$ 
Involved directory: 
/home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (27.66 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (17.25 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.51 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (97.69 seconds)
test.wrap.callVariants: (4 checks) ... OK (12.19 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (23.78 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (3.56 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.2 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (1.95 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (31.84 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (27.77 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.89 seconds)
test.isSparse: (5 checks) ... OK (0.12 seconds)
test.mergeCoverage: (1 checks) ... OK (1.26 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.2 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.36 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.43 seconds)
test.getConfig: (14 checks) ... OK (0 seconds)
test.loadConfig: (2 checks) ... OK (0 seconds)
test.parseDCF: (7 checks) ... OK (0 seconds)
test.updateConfig: (1 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.05 seconds)
test.isAdapter: (5 checks) ... OK (0.15 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.11 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.27 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.46 seconds)
test.getRRNAIds: (1 checks) ... OK (0.28 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.16 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.08 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.06 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.05 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.gatk.R 
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.21 seconds)
test.gatk : DEACTIVATED, gatk() tests need gatk.path option set
test.realignIndels : DEACTIVATED, test.realignIndels() tests need gatk.path option set
test.realignIndelsGATK : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test.realignIndelsGATK.parallel : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test_zipUp: (3 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.19 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.34 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.2 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.2 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.57 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.14 seconds)
test.getObjectFilename: (4 checks) ... OK (0.01 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.17 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (58.22 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.picard.R 
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (9.07 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (14.64 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (7.82 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.12 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.12 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.14 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.06 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (43.41 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.31 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (13.99 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.08 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.23 seconds) 

runTests.R: OK !
There were 50 or more warnings (use warnings() to see the first 50)
> 
> proc.time()
   user  system elapsed 
279.936  93.534 419.204

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

name	user	system	elapsed
HTSeqGenie	0	0	0
buildGenomicFeaturesFromTxDb	0	0	0
runPipeline	0	0	0