Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

CRAM CompressionHeader producing stream of DEBUG log entries #649

Closed
jrobinso opened this issue Jun 23, 2016 · 4 comments
Closed

CRAM CompressionHeader producing stream of DEBUG log entries #649

jrobinso opened this issue Jun 23, 2016 · 4 comments
Labels

Comments

@jrobinso
Copy link
Contributor

Using the htsjdk to decode CRAM records from IGV produces a large stream of DEBUG statements. I use log4j, but do not have any debug flags set. This appears to be default behavior for the htsjdk, and in addition to overflowing the igv.log probably impacts performance.

Here is a small sampling

DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: BF_BitFlags, HUFFMAN, [24, 0, 16, 65, 67, 69, 81, 83, 85, -128, -127, -128, -125, -128, -123, -128, -111, -128, -109, -128].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: AP_AlignmentPositionOffset, SUBEXPONENTIAL, [0, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: FP_FeaturePosition, SUBEXPONENTIAL, [0, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: FC_FeatureCode, HUFFMAN, [4, 68, 83, 88, 105, 4, 3, 2, 1, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: QS_QualityScore, EXTERNAL, [1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: DL_DeletionLength, HUFFMAN, [6, 1, 2, 4, 5, 6, 15, 6, 1, 2, 5, 4, 3, 5, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: BA_Base, EXTERNAL, [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: TN_TagNameAndType, HUFFMAN, [14, -32, 65, 77, 99, -32, 77, 81, 99, -32, 79, 67, 90, -32, 79, 80, 105, -32, 83, 77].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: NF_RecordsToNextFragment, HUFFMAN, [48, -1, -1, -1, -1, -1, 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: RL_ReadLength, HUFFMAN, [1, 101, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: RG_ReadGroup, HUFFMAN, [1, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: MQ_MappingQualityScore, HUFFMAN, [40, 0, 3, 5, 8, 9, 10, 11, 15, 16, 17, 18, 23, 25, 29, 30, 33, 34, 35, 36].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: RN_ReadName, BYTE_ARRAY_LEN, [3, 6, 2, 17, 18, 2, 1, 1, 1, 1, 2, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: NP_NextFragmentAlignmentStart, EXTERNAL, [3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: TS_InsetSize, EXTERNAL, [3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: FN_NumberOfReadFeatures, HUFFMAN, [13, 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 1, 2, 3, 4, 5].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: BS_BaseSubstitutionCode, HUFFMAN, [4, 0, 1, 2, 3, 4, 1, 2, 3, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: IN_Insertion, BYTE_ARRAY_STOP, [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: TC_TagCount, HUFFMAN, [10, 0, 1, 3, 4, 5, 6, 7, 8, 9, 10, 10, 9, 5, 7, 4, 3, 1, 2, 6].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: MF_MateBitFlags, HUFFMAN, [4, 0, 1, 2, 3, 4, 1, 2, 3, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: NS_NextFragmentReferenceSequenceID, HUFFMAN, [13, -1, -1, -1, -1, -1, 0, 1, 2, 6, 8, 11, 13, 14, 16, 18, 19, 21, 13, 1].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: CF_CompressionBitFlags, HUFFMAN, [3, 1, 3, 5, 3, 2, 2, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: TL_TagIdList, HUFFMAN, [34, 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: RI_RefId, HUFFMAN, [1, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: RS_RefSkip, HUFFMAN, [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: SC_SoftClip, BYTE_ARRAY_STOP, [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: HC_HardClip, HUFFMAN, [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: PD_padding, HUFFMAN, [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 ContainerIO READ CONTAINER: seqID=0, start=55999043, span=175401, records=10000, slices=1, blocks=8.
DEBUG 2016-06-23 15:38:42 ContainerParser Adding external data: 0
DEBUG 2016-06-23 15:38:42 ContainerParser Adding external data: 1
DEBUG 2016-06-23 15:38:42 ContainerParser Adding external data: 2
DEBUG 2016-06-23 15:38:42 ContainerParser Adding external data: 3
DEBUG 2016-06-23 15:38:42 ContainerParser Adding external data: 4
DEBUG 2016-06-23 15:38:42 ContainerParser Slice records read time: 9
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: BF_BitFlags, HUFFMAN, [24, 0, 16, 65, 67, 69, 81, 83, 85, -128, -127, -128, -125, -128, -123, -128, -111, -128, -109, -128].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: AP_AlignmentPositionOffset, SUBEXPONENTIAL, [0, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: FP_FeaturePosition, SUBEXPONENTIAL, [0, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: FC_FeatureCode, HUFFMAN, [4, 68, 83, 88, 105, 4, 3, 2, 1, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: QS_QualityScore, EXTERNAL, [1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: DL_DeletionLength, HUFFMAN, [6, 1, 2, 3, 4, 5, 11, 6, 1, 3, 4, 3, 4, 3, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: BA_Base, EXTERNAL, [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: TN_TagNameAndType, HUFFMAN, [14, -32, 65, 77, 99, -32, 77, 81, 99, -32, 79, 67, 90, -32, 79, 80, 105, -32, 83, 77].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: NF_RecordsToNextFragment, HUFFMAN, [44, -1, -1, -1, -1, -1, 0, 1, 2, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: RL_ReadLength, HUFFMAN, [1, 101, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: RG_ReadGroup, HUFFMAN, [1, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: MQ_MappingQualityScore, HUFFMAN, [31, 0, 2, 4, 5, 9, 13, 15, 17, 18, 22, 25, 29, 35, 36, 37, 38, 42, 43, 46].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: RN_ReadName, BYTE_ARRAY_LEN, [3, 6, 2, 17, 18, 2, 1, 1, 1, 1, 2, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: NP_NextFragmentAlignmentStart, EXTERNAL, [3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: TS_InsetSize, EXTERNAL, [3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: FN_NumberOfReadFeatures, HUFFMAN, [11, 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 1, 2, 3, 4, 5, 6, 7].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: BS_BaseSubstitutionCode, HUFFMAN, [4, 0, 1, 2, 3, 4, 1, 2, 3, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: IN_Insertion, BYTE_ARRAY_STOP, [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: TC_TagCount, HUFFMAN, [8, 1, 3, 4, 5, 6, 7, 8, 9, 8, 6, 7, 4, 3, 1, 2, 5, 7, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: MF_MateBitFlags, HUFFMAN, [4, 0, 1, 2, 3, 4, 1, 2, 3, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: NS_NextFragmentReferenceSequenceID, HUFFMAN, [12, -1, -1, -1, -1, -1, 0, 1, 3, 6, 10, 11, 13, 15, 22, 65, 85, 12, 1, 2].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: CF_CompressionBitFlags, HUFFMAN, [3, 1, 3, 5, 3, 2, 2, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0].
DEBUG 2016-06-23 15:38:42 CompressionHeader FOUND ENCODING: TL_

@cmnbroad
Copy link
Collaborator

Yes, it would be nice to get rid of these, though as you say the real issue is that for some reason htsjdk defaults to LogLevel.DEBUG.

@cmnbroad cmnbroad added the cram label Jun 24, 2016
@cmnbroad
Copy link
Collaborator

Marking as a CRAM issue since it mostly affects CRAM, even though technically its not. (Other than CRAM there is very little code dependent on the debug level, only a little SRA code IIRC).

@cmnbroad
Copy link
Collaborator

I believe this is fixed now by #740, but I'll wait to close until I verify.

@jrobinso
Copy link
Contributor Author

I reported the problem, and its indeed fixed. Will close.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants