##############################################################################
##############################################################################
###
### 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.1 (2024-06-14)
* using platform: aarch64-unknown-linux-gnu
* R was compiled by
    gcc (GCC) 12.2.1 20220819 (openEuler 12.2.1-14)
    GNU Fortran (GCC) 10.3.1
* running under: openEuler 22.03 (LTS-SP1)
* 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.

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


* installing to library ‘/home/biocbuild/R/R-4.4.1/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)

R version 4.4.1 (2024-06-14) -- "Race for Your Life"
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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:05:31.575989 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-05 09:05:31.585612 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:05:31.592385 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-05 09:05:31.595221 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:05:35.411143 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:05:35.413246 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/chunks/chunk_000001/logs/progress.log
2024-11-05 09:05:38.299329 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2024-11-05 09:05:38.301183 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/chunks/chunk_000002/logs/progress.log
2024-11-05 09:05:41.146316 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2024-11-05 09:05:41.148129 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/chunks/chunk_000003/logs/progress.log
2024-11-05 09:05:44.048784 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2024-11-05 09:05:44.09127 DEBUG::tools.R/processChunks: done
2024-11-05 09:05:44.096298 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-05 09:05:44.099469 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/results/test_pe.adapter_contaminated_1.RData
2024-11-05 09:05:44.103326 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-05 09:05:44.105847 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/results/test_pe.adapter_contaminated_2.RData
2024-11-05 09:05:44.118543 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
2024-11-05 09:05:44.121782 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/results/test_pe.summary_preprocess.tab
2024-11-05 09:05:44.126537 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/bams/processed.aligner_input_1.fastq ...
2024-11-05 09:05:44.133822 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/bams/processed.aligner_input_2.fastq ...
2024-11-05 09:05:44.140111 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/reports/shortReadReport_1 ...
2024-11-05 09:05:46.044379 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/reports/shortReadReport_2 ...
2024-11-05 09:05:47.638278 INFO::preprocessReads.R/preprocessReads: done
2024-11-05 09:05:47.695219 INFO::alignReads.R/alignReads: starting alignment...
2024-11-05 09:05:47.701415 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:05:51.033559 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:05:51.040652 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/chunks/chunk_000001/logs/progress.log
2024-11-05 09:05:54.21294 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.053 minutes
2024-11-05 09:05:54.215359 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/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.
[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.
2024-11-05 09:05:56.922253 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-11-05 09:05:56.924787 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/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.
2024-11-05 09:05:59.604956 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-11-05 09:05:59.608217 DEBUG::tools.R/processChunks: done
2024-11-05 09:05:59.610081 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 "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.
2024-11-05 09:05:59.943237 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-05 09:05:59.95779 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/results/test_pe.summary_alignment.tab
2024-11-05 09:05:59.969448 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/results/test_pe.summary_analyzed_bamstats.tab
2024-11-05 09:05:59.97219 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-05 09:06:00.267336 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.2381a03368eb86/results/test_pe.summary_target_lengths.tab
2024-11-05 09:06:00.332585 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-05 09:06:00.333947 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:06:00.631989 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-05 09:06:00.635965 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:06:00.732866 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-11-05 09:06:00.739799 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:06:00.744321 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-05 09:06:00.747164 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:06:04.55655 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:06:04.558525 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/chunks/chunk_000001/logs/progress.log
2024-11-05 09:06:07.373748 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-11-05 09:06:07.375585 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/chunks/chunk_000002/logs/progress.log
2024-11-05 09:06:10.212059 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2024-11-05 09:06:10.213965 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/chunks/chunk_000003/logs/progress.log
2024-11-05 09:06:13.133309 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.049 minutes
2024-11-05 09:06:13.135118 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/chunks/chunk_000004/logs/progress.log
2024-11-05 09:06:15.935414 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.047 minutes
2024-11-05 09:06:15.974592 DEBUG::tools.R/processChunks: done
2024-11-05 09:06:15.978941 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-05 09:06:15.982078 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/results/test_pe.adapter_contaminated_1.RData
2024-11-05 09:06:15.98609 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-05 09:06:15.988548 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/results/test_pe.adapter_contaminated_2.RData
2024-11-05 09:06:16.002052 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
2024-11-05 09:06:16.00504 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/results/test_pe.summary_preprocess.tab
2024-11-05 09:06:16.009692 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/bams/processed.aligner_input_1.fastq ...
2024-11-05 09:06:16.016882 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/bams/processed.aligner_input_2.fastq ...
2024-11-05 09:06:16.022477 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/reports/shortReadReport_1 ...
2024-11-05 09:06:17.96328 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReads.sparsechunks.2381a06f9df8b9/reports/shortReadReport_2 ...
2024-11-05 09:06:19.506549 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:06:19.707388 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-11-05 09:06:19.714208 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/RtmpMN2AT8/test.alignReadsOneSingleEnd.2381a04e64b33e/bams/test.alignReads /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-11-05 09:06:19.855099 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-11-05 09:06:19.994276 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReadsOneSingleEnd.2381a04e64b33e/results/test.alignReads.summary_alignment.tab
2024-11-05 09:06:20.047831 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.alignReadsOneSingleEnd.2381a04e64b33e/results/test.alignReads.summary_analyzed_bamstats.tab
2024-11-05 09:06:20.050117 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.002 0.003 0.003
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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:06:20.476776 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.genotype.2381a062679d88/results/test_pe.coverage.RData
2024-11-05 09:06:20.479563 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.genotype.2381a062679d88/results/test_pe.coverage.bw
2024-11-05 09:06:20.667477 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.genotype.2381a062679d88/results/test_pe.summary_coverage.tab
2024-11-05 09:06:20.669858 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-05 09:06:33.891419 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-05 09:06:34.060548 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-05 09:06:34.094221 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-05 09:06:34.096823 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.genotype.2381a062679d88/results/test_pe.raw_variants.RData
2024-11-05 09:06:34.100568 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.genotype.2381a062679d88/results/test_pe.filtered_variants.RData
2024-11-05 09:06:34.103023 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-05 09:06:34.105241 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-05 09:06:34.817977 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-05 09:06:34.819824 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-11-05 09:07:59.443332 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-05 09:08:00.076663 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-05 09:08:00.078015 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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:08:00.708608 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-05 09:08:13.650726 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-05 09:08:13.763386 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-05 09:08:13.788627 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-05 09:08:13.790573 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.wrap.callVariants.2381a0201c61f5/results/test_pe.raw_variants.RData
2024-11-05 09:08:13.793679 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.wrap.callVariants.2381a0201c61f5/results/test_pe.filtered_variants.RData
2024-11-05 09:08:13.795594 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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:08:15.762846 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-05 09:08:28.590738 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-05 09:08:28.677289 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-05 09:08:28.702377 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-05 09:08:28.704316 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.wrap.callVariants.filters.2381a04f24d9c1/results/test_pe.raw_variants.RData
2024-11-05 09:08:28.70744 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.wrap.callVariants.filters.2381a04f24d9c1/results/test_pe.filtered_variants.RData
2024-11-05 09:08:28.709259 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-05 09:08:28.71118 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-05 09:08:41.657197 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-05 09:08:41.718054 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-05 09:08:41.744917 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-05 09:08:41.746951 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.wrap.callVariants.filters.2381a04f24d9c1/results/test_pe.raw_variants.RData
2024-11-05 09:08:41.750449 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.wrap.callVariants.filters.2381a04f24d9c1/results/test_pe.filtered_variants.RData
2024-11-05 09:08:41.753233 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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:08:42.03475 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-05 09:08:42.036921 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-11-05 09:08:45.617656 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-05 09:08:45.725881 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-05 09:08:45.749378 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-05 09:08:45.751253 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.wrap.callVariants.which.2381a036607209/results/test_pe.raw_variants.RData
2024-11-05 09:08:45.753523 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.wrap.callVariants.which.2381a036607209/results/test_pe.filtered_variants.RData
2024-11-05 09:08:45.755238 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:08:45.920096 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-05 09:08:45.921816 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:08:46.149626 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-05 09:08:46.448209 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  ... 2024-11-05 09:10:00.397688 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/kedjrhcb/merged/results/bla.coverage.RData
2024-11-05 09:10:00.401044 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpMN2AT8/kedjrhcb/merged/results/bla.coverage.bw
2024-11-05 09:10:00.518163 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/kedjrhcb/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-11-05 09:10:01.921302 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/cadzblxv/merged/results/bla.coverage.RData
2024-11-05 09:10:01.923674 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpMN2AT8/cadzblxv/merged/results/bla.coverage.bw
2024-11-05 09:10:01.938492 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/cadzblxv/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:10:03.614348 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-11-05 09:10:03.616096 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpMN2AT8/test.detectRRNA.2381a0631259b3/bams/rRNA_contam/input1.fastq
2024-11-05 09:10:03.620657 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/RtmpMN2AT8/test.detectRRNA.2381a0631259b3/bams/rRNA_contam/test_se /home/biocbuild/tmp/RtmpMN2AT8/test.detectRRNA.2381a0631259b3/bams/rRNA_contam/input1.fastq 2>&1
2024-11-05 09:10:03.731962 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-11-05 09:10:03.733382 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:10:03.887139 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-11-05 09:10:03.888489 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpMN2AT8/test.detectRRNA.paired_end.2381a063036540/bams/rRNA_contam/input1.fastq
2024-11-05 09:10:03.890635 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpMN2AT8/test.detectRRNA.paired_end.2381a063036540/bams/rRNA_contam/input2.fastq
2024-11-05 09:10:03.893858 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/RtmpMN2AT8/test.detectRRNA.paired_end.2381a063036540/bams/rRNA_contam/test_pe /home/biocbuild/tmp/RtmpMN2AT8/test.detectRRNA.paired_end.2381a063036540/bams/rRNA_contam/input1.fastq -a paired /home/biocbuild/tmp/RtmpMN2AT8/test.detectRRNA.paired_end.2381a063036540/bams/rRNA_contam/input2.fastq 2>&1
2024-11-05 09:10:04.146157 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-11-05 09:10:04.147578 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-11-05 09:10:04.176295 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/RtmpMN2AT8/test_get_rRNA_idsmpakvbqe/test_pe /home/biocbuild/tmp/RtmpMN2AT8/test_get_rRNA_idsmpakvbqe/1.fastq -a paired /home/biocbuild/tmp/RtmpMN2AT8/test_get_rRNA_idsmpakvbqe/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-11-05 09:10:04.473706 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/RtmpMN2AT8/test_get_rRNAIds_randomrjvmsayx/test_pe /home/biocbuild/tmp/RtmpMN2AT8/test_get_rRNAIds_randomrjvmsayx/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-11-05 09:10:04.690547 INFO::filterQuality.R/filterQuality: filterByLength...
2024-11-05 09:10:04.692633 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-11-05 09:10:04.69397 INFO::filterQuality.R/filterByLength: done
2024-11-05 09:10:04.765188 INFO::filterQuality.R/filterQuality: filterByLength...
2024-11-05 09:10:04.766464 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-11-05 09:10:04.767727 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-11-05 09:10:04.842085 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-05 09:10:04.854875 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-11-05 09:10:04.856411 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-05 09:10:04.863005 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-11-05 09:10:04.864516 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-05 09:10:04.871149 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-11-05 09:10:04.872683 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-05 09:10:04.87934 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



Executing test function test.callVariantsGATK  ... Timing stopped at: 0 0 0
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.001 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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:10:05.240624 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:10:05.243958 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:10:05.444282 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:10:05.554286 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-11-05 09:10:05.558176 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:10:05.561418 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:10:05.847238 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:10:06.042351 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:10:06.276985 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:10:06.350266 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-11-05 09:10:06.353853 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:10:06.357147 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:10:06.625688 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:10:06.700121 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-11-05 09:10:06.708998 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:10:06.712448 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:10:07.580763 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-05 09:10:07.587918 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:10:07.592763 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-05 09:10:07.595972 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:10:12.692789 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:10:12.694846 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000001/logs/progress.log
2024-11-05 09:10:15.463262 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-11-05 09:10:15.465186 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000002/logs/progress.log
2024-11-05 09:10:18.298913 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2024-11-05 09:10:18.301184 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000003/logs/progress.log
2024-11-05 09:10:21.057962 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-11-05 09:10:21.126314 DEBUG::tools.R/processChunks: done
2024-11-05 09:10:21.130014 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-05 09:10:21.132409 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.adapter_contaminated_1.RData
2024-11-05 09:10:21.135528 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-05 09:10:21.137875 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.adapter_contaminated_2.RData
2024-11-05 09:10:21.149213 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
2024-11-05 09:10:21.151942 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.summary_preprocess.tab
2024-11-05 09:10:21.155862 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/bams/processed.aligner_input_1.fastq ...
2024-11-05 09:10:21.163187 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/bams/processed.aligner_input_2.fastq ...
2024-11-05 09:10:21.16919 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/reports/shortReadReport_1 ...
2024-11-05 09:10:23.043634 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/reports/shortReadReport_2 ...
2024-11-05 09:10:24.594557 INFO::preprocessReads.R/preprocessReads: done
2024-11-05 09:10:24.668874 INFO::alignReads.R/alignReads: starting alignment...
2024-11-05 09:10:24.673894 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:10:28.507349 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:10:28.509678 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000001/logs/progress.log
2024-11-05 09:10:31.127182 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-11-05 09:10:31.129386 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/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.
[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.
2024-11-05 09:10:33.791279 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-11-05 09:10:33.793544 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/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.
2024-11-05 09:10:36.409992 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-11-05 09:10:36.413554 DEBUG::tools.R/processChunks: done
2024-11-05 09:10:36.415768 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 "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.
2024-11-05 09:10:36.726288 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-05 09:10:36.737153 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.summary_alignment.tab
2024-11-05 09:10:36.748303 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.summary_analyzed_bamstats.tab
2024-11-05 09:10:36.75091 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-05 09:10:37.012912 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.summary_target_lengths.tab
2024-11-05 09:10:37.076595 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-05 09:10:37.077988 INFO::alignReads.R/alignReads: done
2024-11-05 09:10:37.152513 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-11-05 09:10:37.174333 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:10:41.02091 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:10:41.023017 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000001/logs/progress.log
2024-11-05 09:10:43.57025 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-11-05 09:10:43.57248 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000002/logs/progress.log
2024-11-05 09:10:46.159357 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-11-05 09:10:46.161792 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000003/logs/progress.log
2024-11-05 09:10:48.717564 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-11-05 09:10:48.720989 DEBUG::tools.R/processChunks: done
2024-11-05 09:10:48.723236 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-11-05 09:10:48.740829 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.counts_exon.tab
2024-11-05 09:10:48.755193 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.counts_exon_disjoint.tab
2024-11-05 09:10:48.765051 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.counts_gene.tab
2024-11-05 09:10:48.77336 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.counts_gene_coding.tab
2024-11-05 09:10:48.78152 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.counts_gene_exonic.tab
2024-11-05 09:10:48.789482 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.counts_intergenic.tab
2024-11-05 09:10:48.802119 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.counts_intron.tab
2024-11-05 09:10:48.80588 INFO::countGenomicFeatures.R/mergeCounts: done
2024-11-05 09:10:48.814468 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.summary_counts.tab
2024-11-05 09:10:48.816939 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-11-05 09:10:49.189639 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-11-05 09:10:49.190936 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-11-05 09:10:49.269073 INFO::coverage.R/calculateCoverage: starting...
2024-11-05 09:10:49.273526 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:10:52.843241 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:10:52.845433 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000001/logs/progress.log
2024-11-05 09:10:55.03942 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2024-11-05 09:10:55.041783 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000002/logs/progress.log
2024-11-05 09:10:57.245829 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2024-11-05 09:10:57.248115 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/chunks/chunk_000003/logs/progress.log
2024-11-05 09:10:59.440198 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2024-11-05 09:10:59.443476 DEBUG::tools.R/processChunks: done
2024-11-05 09:11:01.231328 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.coverage.RData
2024-11-05 09:11:01.23312 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.coverage.bw
2024-11-05 09:11:01.24913 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.summary_coverage.tab
2024-11-05 09:11:01.251025 INFO::coverage.R/calculateCoverage: done
2024-11-05 09:11:01.253191 INFO::analyzeVariants/analyzeVariants: starting ...
2024-11-05 09:11:01.329956 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-05 09:11:05.145198 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-05 09:11:05.25874 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-05 09:11:05.284974 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-05 09:11:05.28703 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.raw_variants.RData
2024-11-05 09:11:05.289805 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.filtered_variants.RData
2024-11-05 09:11:05.291719 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-05 09:11:05.293186 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-05 09:11:05.605603 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-05 09:11:05.746398 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/results/test_pe.summary_variants.tab
2024-11-05 09:11:05.748873 INFO::analyzeVariants/analyzeVariants: done
2024-11-05 09:11:05.752527 INFO::Pipeline run successful.
2024-11-05 09:11:05.926301 INFO::mergeLanes.R/doMergeLanes: starting...
2024-11-05 09:11:05.932152 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-05 09:11:05.935501 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.adapter_contaminated_1.RData
2024-11-05 09:11:05.939602 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-05 09:11:05.942686 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.adapter_contaminated_2.RData
2024-11-05 09:11:05.958102 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
2024-11-05 09:11:05.961349 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.summary_preprocess.tab
2024-11-05 09:11:05.964446 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 "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.
2024-11-05 09:11:06.297411 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-05 09:11:06.307369 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.summary_alignment.tab
2024-11-05 09:11:06.319366 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.summary_analyzed_bamstats.tab
2024-11-05 09:11:06.322346 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-05 09:11:06.598746 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.summary_target_lengths.tab
2024-11-05 09:11:06.666962 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-05 09:11:06.711005 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-11-05 09:11:06.737073 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.counts_exon.tab
2024-11-05 09:11:06.753753 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.counts_exon_disjoint.tab
2024-11-05 09:11:06.764136 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.counts_gene.tab
2024-11-05 09:11:06.772564 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.counts_gene_coding.tab
2024-11-05 09:11:06.780863 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.counts_gene_exonic.tab
2024-11-05 09:11:06.789412 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.counts_intergenic.tab
2024-11-05 09:11:06.805921 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.counts_intron.tab
2024-11-05 09:11:06.809925 INFO::countGenomicFeatures.R/mergeCounts: done
2024-11-05 09:11:06.819639 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.summary_counts.tab
2024-11-05 09:11:06.822287 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-11-05 09:11:07.127681 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-11-05 09:11:09.481628 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.coverage.RData
2024-11-05 09:11:09.484498 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.coverage.bw
2024-11-05 09:11:09.50075 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.summary_coverage.tab
2024-11-05 09:11:09.542628 INFO::analyzeVariants/analyzeVariants: starting ...
2024-11-05 09:11:09.621207 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-05 09:11:14.487848 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-05 09:11:14.601923 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-05 09:11:14.627616 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-05 09:11:14.629648 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.raw_variants.RData
2024-11-05 09:11:14.632071 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.filtered_variants.RData
2024-11-05 09:11:14.633919 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-05 09:11:14.635433 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-05 09:11:14.975527 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-05 09:11:15.129668 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.mergeLanes.2381a026912fa6/merged/results/merged.summary_variants.tab
2024-11-05 09:11:15.132707 INFO::analyzeVariants/analyzeVariants: done
2024-11-05 09:11:15.136018 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0 0 0.001
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/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:11:15.459994 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-05 09:11:15.466896 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:11:15.471507 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-05 09:11:15.474473 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:11:20.686765 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:11:20.68885 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.2381a0631b975c/chunks/chunk_000001/logs/progress.log
2024-11-05 09:11:23.492277 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-11-05 09:11:23.571707 DEBUG::tools.R/processChunks: done
2024-11-05 09:11:23.575193 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-05 09:11:23.577524 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.2381a0631b975c/results/test_pe.adapter_contaminated_1.RData
2024-11-05 09:11:23.580138 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-05 09:11:23.582443 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.2381a0631b975c/results/test_pe.adapter_contaminated_2.RData
2024-11-05 09:11:23.591621 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
2024-11-05 09:11:23.594732 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.2381a0631b975c/results/test_pe.summary_preprocess.tab
2024-11-05 09:11:23.598382 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.2381a0631b975c/bams/processed.aligner_input_1.fastq ...
2024-11-05 09:11:23.60491 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.2381a0631b975c/bams/processed.aligner_input_2.fastq ...
2024-11-05 09:11:23.611136 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.2381a0631b975c/reports/shortReadReport_1 ...
2024-11-05 09:11:25.520308 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.2381a0631b975c/reports/shortReadReport_2 ...
2024-11-05 09:11:27.090497 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:11:27.337059 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-05 09:11:27.344075 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:11:27.348778 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-05 09:11:27.351954 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:11:32.522703 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:11:32.524769 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/chunks/chunk_000001/logs/progress.log
2024-11-05 09:11:35.294198 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-11-05 09:11:35.296113 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/chunks/chunk_000002/logs/progress.log
2024-11-05 09:11:38.044724 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-11-05 09:11:38.046705 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/chunks/chunk_000003/logs/progress.log
2024-11-05 09:11:40.783657 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-11-05 09:11:40.850178 DEBUG::tools.R/processChunks: done
2024-11-05 09:11:40.853828 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-05 09:11:40.856196 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/results/test_pe.adapter_contaminated_1.RData
2024-11-05 09:11:40.859166 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-05 09:11:40.861477 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/results/test_pe.adapter_contaminated_2.RData
2024-11-05 09:11:40.87235 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
2024-11-05 09:11:40.874943 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/results/test_pe.summary_preprocess.tab
2024-11-05 09:11:40.878478 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/bams/processed.aligner_input_1.fastq ...
2024-11-05 09:11:40.885304 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/bams/processed.aligner_input_2.fastq ...
2024-11-05 09:11:40.891268 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/reports/shortReadReport_1 ...
2024-11-05 09:11:42.71443 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads.minichunks.2381a0476889ea/reports/shortReadReport_2 ...
2024-11-05 09:11:44.262565 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:11:44.571437 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-05 09:11:44.57867 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-05 09:11:44.581688 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:11:48.696996 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:11:48.699108 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads_single_end.2381a0248eabb5/chunks/chunk_000001/logs/progress.log
2024-11-05 09:11:51.122253 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-11-05 09:11:51.180766 DEBUG::tools.R/processChunks: done
2024-11-05 09:11:51.183906 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-05 09:11:51.186285 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads_single_end.2381a0248eabb5/results/test_se.adapter_contaminated_1.RData
2024-11-05 09:11:51.194852 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
2024-11-05 09:11:51.197236 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads_single_end.2381a0248eabb5/results/test_se.summary_preprocess.tab
2024-11-05 09:11:51.199795 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads_single_end.2381a0248eabb5/bams/processed.aligner_input_1.fastq ...
2024-11-05 09:11:51.205209 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpMN2AT8/test.preprocessReads_single_end.2381a0248eabb5/reports/shortReadReport_1 ...
2024-11-05 09:11:53.040225 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.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:11:53.815802 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-05 09:11:53.83844 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-11-05 09:11:53.859411 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-11-05 09:11:53.862418 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:11:57.526367 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:11:57.528415 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-11-05 09:12:00.560616 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2024-11-05 09:12:00.636788 DEBUG::tools.R/processChunks: done
2024-11-05 09:12:00.640074 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-05 09:12:00.642287 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-11-05 09:12:00.644723 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-05 09:12:00.646962 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-11-05 09:12:00.655478 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
2024-11-05 09:12:00.657974 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-11-05 09:12:00.660878 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-11-05 09:12:00.667798 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-11-05 09:12:00.674476 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-11-05 09:12:02.844964 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2024-11-05 09:12:04.820674 INFO::preprocessReads.R/preprocessReads: done
2024-11-05 09:12:04.898186 INFO::alignReads.R/alignReads: starting alignment...
2024-11-05 09:12:04.90325 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:12:08.718625 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:12:08.720789 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.
2024-11-05 09:12:14.549163 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.097 minutes
2024-11-05 09:12:14.552393 DEBUG::tools.R/processChunks: done
2024-11-05 09:12:14.554237 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2024-11-05 09:12:14.59036 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-05 09:12:14.598469 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2024-11-05 09:12:14.605948 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2024-11-05 09:12:14.608696 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-05 09:12:14.807849 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2024-11-05 09:12:14.87077 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-05 09:12:14.872106 INFO::alignReads.R/alignReads: done
2024-11-05 09:12:14.951591 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-11-05 09:12:14.972182 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:12:20.17224 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:12:20.174557 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-11-05 09:12:22.801426 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-11-05 09:12:22.804779 DEBUG::tools.R/processChunks: done
2024-11-05 09:12:22.806846 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-11-05 09:12:22.818779 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2024-11-05 09:12:22.828843 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2024-11-05 09:12:22.840998 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2024-11-05 09:12:22.846184 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2024-11-05 09:12:22.851274 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2024-11-05 09:12:22.856329 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2024-11-05 09:12:22.864235 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2024-11-05 09:12:22.868263 INFO::countGenomicFeatures.R/mergeCounts: done
2024-11-05 09:12:22.872948 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2024-11-05 09:12:22.875175 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-11-05 09:12:23.155444 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-11-05 09:12:23.15666 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-11-05 09:12:23.232928 INFO::coverage.R/calculateCoverage: starting...
2024-11-05 09:12:23.238325 DEBUG::tools.R/processChunks: starting...
2024-11-05 09:12:29.005229 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-05 09:12:29.007745 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-11-05 09:12:31.408379 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-11-05 09:12:31.411863 DEBUG::tools.R/processChunks: done
2024-11-05 09:12:33.218004 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2024-11-05 09:12:33.219976 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2024-11-05 09:12:33.327597 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2024-11-05 09:12:33.329388 INFO::coverage.R/calculateCoverage: done
2024-11-05 09:12:33.331061 INFO::analyzeVariants/analyzeVariants: starting ...
2024-11-05 09:12:33.411324 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-05 09:12:47.72548 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-05 09:12:47.894668 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-05 09:12:47.93073 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-05 09:12:47.933518 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2024-11-05 09:12:47.937751 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2024-11-05 09:12:47.940374 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-05 09:12:47.942489 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-05 09:12:48.458965 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-05 09:12:48.661221 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2024-11-05 09:12:48.665397 INFO::analyzeVariants/analyzeVariants: done
2024-11-05 09:12:48.671475 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpMN2AT8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-11-05 09:12:48.974285 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpMN2AT8/test.calcTargetLengths.2381a039ce8178/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 Nov  5 09:13:04 2024 
*********************************************** 
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.1/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (30.49 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (19.17 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.54 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (100.49 seconds)
test.wrap.callVariants: (4 checks) ... OK (13.25 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (27.96 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (4 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.17 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.66 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (37.74 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (33.29 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.94 seconds)
test.isSparse: (5 checks) ... OK (0.13 seconds)
test.mergeCoverage: (1 checks) ... OK (1.83 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.45 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/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.1/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.43 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.46 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.1/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.05 seconds)
test.isAdapter: (5 checks) ... OK (0.16 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.12 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.32 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.41 seconds)
test.getRRNAIds: (1 checks) ... OK (0.29 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.24 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/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.1/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.1/site-library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.21 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.39 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.21 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.19 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.7 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.17 seconds)
test.getObjectFilename: (4 checks) ... OK (0.01 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.22 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (67.96 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/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.1/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (11.93 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (17.17 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (8.78 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.12 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.13 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/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.05 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (55.18 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.3 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (14.79 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.08 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.26 seconds) 

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