CGATOxford / UMI-tools

Tools for handling Unique Molecular Identifiers in NGS data sets
MIT License
491 stars 190 forks source link

umi_tools dedup error #512

Closed diwasri closed 8 months ago

diwasri commented 2 years ago

Hi, I am trying to do deduplication of my bam files using umi_tools dedup with the following command. The process seems to work for a few reads and then is giving me an error.

for i in *.bam; do umi_tools dedup -I $i −−paired −−output−stats=deduplicated −S ./Deduplicated/${i%%.Aligned.sortedByCoord.out.bam}_dedup.bam; done

This is the log of the run for the first bam file.

UMI-tools version: 1.1.2
output generated by dedup -I 91762.Aligned.sortedByCoord.out.bam −−paired −−output−stats=deduplicated −S ./Deduplicated/91762_dedup.bam
job started at Fri Feb 11 21:23:03 2022 on fe7c0e95a6a7 -- 2dd96599-588b-4021-8f0c-aac73549a24e
pid: 13301, system: Linux 4.4.0-1065-aws #75-Ubuntu SMP Fri Aug 10 11:14:32 UTC 2018 x86_64
assigned_tag                            : None
cell_tag                                : None
cell_tag_delim                          : None
cell_tag_split                          : -
chimeric_pairs                          : use
chrom                                   : None
compresslevel                           : 6
detection_method                        : None
filter_umi                              : None
gene_tag                                : None
gene_transcript_map                     : None
get_umi_method                          : read_id
ignore_tlen                             : False
ignore_umi                              : False
in_sam                                  : False
log2stderr                              : False
loglevel                                : 1
mapping_quality                         : 0
method                                  : directional
no_sort_output                          : False
out_sam                                 : False
output_unmapped                         : False
paired                                  : False
per_cell                                : False
per_contig                              : False
per_gene                                : False
random_seed                             : None
read_length                             : False
short_help                              : None
skip_regex                              : ^(__|Unassigned)
soft_clip_threshold                     : 4
spliced                                 : False
stats                                   : False
stderr                                  : <_io.TextIOWrapper name='<stderr>' mode='w' encoding='UTF-8'>
stdin                                   : <_io.TextIOWrapper name='91762.Aligned.sortedByCoord.out.bam' mode='r' encoding='UTF-8'>
stdlog                                  : <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'>
stdout                                  : <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'>
subset                                  : None
threshold                               : 1
timeit_file                             : None
timeit_header                           : None
timeit_name                             : all
tmpdir                                  : None
umi_sep                                 : _
umi_tag                                 : RX
umi_tag_delim                           : None
umi_tag_split                           : None
umi_whitelist                           : None
umi_whitelist_paired                    : None
unmapped_reads                          : discard
unpaired_reads                          : use
whole_contig                            : False
2022-02-11 21:23:03,018 INFO command: dedup -I 91762.Aligned.sortedByCoord.out.bam −−paired −−output−stats=deduplicated −S ./Deduplicated/91762_dedup.bam
2022-02-11 21:23:07,826 INFO Written out 100000 reads
2022-02-11 21:23:12,526 INFO Written out 200000 reads
2022-02-11 21:23:17,263 INFO Written out 300000 reads
2022-02-11 21:23:21,907 INFO Written out 400000 reads
2022-02-11 21:23:26,554 INFO Written out 500000 reads
2022-02-11 21:23:31,284 INFO Written out 600000 reads
2022-02-11 21:23:34,517 INFO Parsed 1000000 input reads
2022-02-11 21:23:36,062 INFO Written out 700000 reads
2022-02-11 21:23:40,851 INFO Written out 800000 reads
2022-02-11 21:23:45,622 INFO Written out 900000 reads
2022-02-11 21:23:50,385 INFO Written out 1000000 reads
2022-02-11 21:23:55,017 INFO Written out 1100000 reads
2022-02-11 21:23:59,692 INFO Written out 1200000 reads
2022-02-11 21:24:04,338 INFO Written out 1300000 reads
2022-02-11 21:24:05,733 INFO Parsed 2000000 input reads
2022-02-11 21:24:09,003 INFO Written out 1400000 reads
2022-02-11 21:24:13,663 INFO Written out 1500000 reads
2022-02-11 21:24:18,305 INFO Written out 1600000 reads
2022-02-11 21:24:22,964 INFO Written out 1700000 reads
2022-02-11 21:24:27,553 INFO Written out 1800000 reads
2022-02-11 21:24:32,173 INFO Written out 1900000 reads
2022-02-11 21:24:36,328 INFO Parsed 3000000 input reads
2022-02-11 21:24:36,796 INFO Written out 2000000 reads
2022-02-11 21:24:41,489 INFO Written out 2100000 reads
2022-02-11 21:24:46,171 INFO Written out 2200000 reads
2022-02-11 21:24:50,829 INFO Written out 2300000 reads
2022-02-11 21:24:55,487 INFO Written out 2400000 reads
2022-02-11 21:25:00,177 INFO Written out 2500000 reads
2022-02-11 21:25:04,886 INFO Written out 2600000 reads
2022-02-11 21:25:07,172 INFO Parsed 4000000 input reads
2022-02-11 21:25:09,576 INFO Written out 2700000 reads
2022-02-11 21:25:14,269 INFO Written out 2800000 reads
2022-02-11 21:25:18,964 INFO Written out 2900000 reads
2022-02-11 21:25:23,645 INFO Written out 3000000 reads
2022-02-11 21:25:28,326 INFO Written out 3100000 reads
2022-02-11 21:25:33,006 INFO Written out 3200000 reads
2022-02-11 21:25:37,698 INFO Written out 3300000 reads
2022-02-11 21:25:38,167 INFO Parsed 5000000 input reads
2022-02-11 21:25:42,387 INFO Written out 3400000 reads
2022-02-11 21:25:47,106 INFO Written out 3500000 reads
2022-02-11 21:25:51,788 INFO Written out 3600000 reads
2022-02-11 21:25:56,483 INFO Written out 3700000 reads
2022-02-11 21:26:01,207 INFO Written out 3800000 reads
2022-02-11 21:26:05,938 INFO Written out 3900000 reads
2022-02-11 21:26:09,315 INFO Parsed 6000000 input reads
2022-02-11 21:26:10,574 INFO Written out 4000000 reads
2022-02-11 21:26:15,250 INFO Written out 4100000 reads
2022-02-11 21:26:19,967 INFO Written out 4200000 reads
2022-02-11 21:26:24,657 INFO Written out 4300000 reads
2022-02-11 21:26:29,339 INFO Written out 4400000 reads
--- Logging error ---
Traceback (most recent call last):
  File "/opt/conda/lib/python3.7/logging/__init__.py", line 1028, in emit
    stream.write(msg + self.terminator)
OSError: [Errno 9] Bad file descriptor
Call stack:
  File "/opt/conda/bin/umi_tools", line 8, in <module>
    sys.exit(main())
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/umi_tools.py", line 61, in main
    module.main(sys.argv)
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/dedup.py", line 451, in main
    bundle_iterator.read_events.most_common()]))
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/Utilities.py", line 1375, in info
    logging.info(message)
Message: 'Reads: Input Reads: 6743883, Chimeric read pair: 3290312'
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
  File "/opt/conda/lib/python3.7/logging/__init__.py", line 1028, in emit
    stream.write(msg + self.terminator)
OSError: [Errno 9] Bad file descriptor
Call stack:
  File "/opt/conda/bin/umi_tools", line 8, in <module>
    sys.exit(main())
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/umi_tools.py", line 61, in main
    module.main(sys.argv)
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/dedup.py", line 453, in main
    U.info("Number of reads out: %i" % nOutput)
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/Utilities.py", line 1375, in info
    logging.info(message)
Message: 'Number of reads out: 4472139'
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
  File "/opt/conda/lib/python3.7/logging/__init__.py", line 1028, in emit
    stream.write(msg + self.terminator)
OSError: [Errno 9] Bad file descriptor
Call stack:
  File "/opt/conda/bin/umi_tools", line 8, in <module>
    sys.exit(main())
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/umi_tools.py", line 61, in main
    module.main(sys.argv)
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/dedup.py", line 457, in main
    processor.UMIClusterer.positions)
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/Utilities.py", line 1375, in info
    logging.info(message)
Message: 'Total number of positions deduplicated: 3212771'
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
  File "/opt/conda/lib/python3.7/logging/__init__.py", line 1028, in emit
    stream.write(msg + self.terminator)
OSError: [Errno 9] Bad file descriptor
Call stack:
  File "/opt/conda/bin/umi_tools", line 8, in <module>
    sys.exit(main())
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/umi_tools.py", line 61, in main
    module.main(sys.argv)
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/dedup.py", line 461, in main
    processor.UMIClusterer.positions))
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/Utilities.py", line 1375, in info
    logging.info(message)
Message: 'Mean number of unique UMIs per position: 1.54'
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
  File "/opt/conda/lib/python3.7/logging/__init__.py", line 1028, in emit
    stream.write(msg + self.terminator)
OSError: [Errno 9] Bad file descriptor
Call stack:
  File "/opt/conda/bin/umi_tools", line 8, in <module>
    sys.exit(main())
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/umi_tools.py", line 61, in main
    module.main(sys.argv)
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/dedup.py", line 463, in main
    processor.UMIClusterer.max_umis_per_position)
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/Utilities.py", line 1375, in info
    logging.info(message)
Message: 'Max. number of unique UMIs per position: 372'
Arguments: ()
Traceback (most recent call last):
  File "/opt/conda/bin/umi_tools", line 8, in <module>
    sys.exit(main())
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/umi_tools.py", line 61, in main
    module.main(sys.argv)
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/dedup.py", line 473, in main
    U.Stop()
  File "/opt/conda/lib/python3.7/site-packages/umi_tools/Utilities.py", line 1322, in Stop
    global_options.stdlog.write(getFooter() + "\n")
OSError: [Errno 9] Bad file descriptor
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'>
OSError: [Errno 9] Bad file descriptor

IanSudbery commented 2 years ago

Thats odd. The error is an error in the logging code, and your bam files should actually be finished and fine (see Exception ignored in the penultimate line). It looks like it is trying to write to a file that no longer exists. But its not because it is writing to stdout, so I don't know how that could be, and it was happily writing to it seconds earlier.

TomSmithCGAT commented 8 months ago

I'm closing due to inactivity