pre-built container?

[RichardCorbett]

Hi there,

I am having trouble getting some of the dependencies installed so I thought I'd try to use your container. Do you have your dockerfile pre-built and posted somewhere? When I search dockerhub some results are returned but they appear to be build from a recipe that is older that your current master Dockerfile.

I can't build docker containers on my local system, but if there is a pre-built container I can run it with singularity.

thanks!

[adamewing]

Will look into it. Per issue #155 it seems there's an issue with the current dockerfile as well. I'm not an avid Docker user so may take some time.

[RichardCorbett]

OK thanks. I'm hoping to use bamsurgeon for an upcoming project so if I have time I might try and drop the requirements into a singularity container. In the best case scenario this can be quite easy, but I never know until I start to put it together.

[RichardCorbett]

Hi again. I built a singularity container based on your dockerfile and the install instructions in the readme. To test it out I tried running addsv.py on an example bam using some mutations from your example in the docs.

Muts.txt: 22 33871043 33874754 DEL 0.75

When I run this it looks like like most steps are doing what they should, but there are some zero counts throughout the trace and the variant isn't successfully integrated. Can you tell if the unsuccessful result is either due to the format of my input bam, missing dependencies, or something else?

Output:

INFO 2020-05-28 08:09:38,104 starting /usr/local/bin/addsv.py called with args: /usr/local/bin/addsv.py -v muts.txt -f /p/B03024_1_lane_dupsFlagged.bam -r /r/hg19a.fa -o test.bam --tmpdir .
INFO 2020-05-28 08:09:38,134 created log directory: addsv_logs_test.bam
INFO 2020-05-28 08:09:38,342 22_33871043_33874754_DEL interval: 22 33871043 33874754 DEL 0.75
INFO 2020-05-28 08:09:38,342 22_33871043_33874754_DEL length: 3711
INFO 2020-05-28 08:09:38,453 22_33871043_33874754_DEL discordant fraction: 0.004036
INFO 2020-05-28 08:10:15,946 found mates for 1000 reads, 0.00 discordant.
INFO 2020-05-28 08:10:24,928 found 1237 reads in region.
[0.000001] Reading FastA file ./22_33871043_33874754_DEL.tmpreads.1e15c451-9f4f-4164-ad51-f8b5bf6f07ae.fasta;
[0.007217] 1314 sequences found
[0.007245] Done
[0.011686] Reading read set file ./22_33871043_33874754_DEL.6c42ffd2/Sequences;
[0.016782] 1314 sequences found
[0.021118] Done
[0.021152] 1314 sequences in total.
[0.024609] Writing into roadmap file ./22_33871043_33874754_DEL.6c42ffd2/Roadmaps...
[0.028252] Inputting sequences...
[0.028277] Inputting sequence 0 / 1314
[0.125794]  === Sequences loaded in 0.097545 s
[0.128947] Done inputting sequences
[0.128999] Destroying splay table
[0.142549] Splay table destroyed
[0.000001] Reading roadmap file ./22_33871043_33874754_DEL.6c42ffd2/Roadmaps
[0.006922] 1314 roadmaps read
[0.006988] Creating insertion markers
[0.007328] Ordering insertion markers
[0.010579] Counting preNodes
[0.010913] 2165 preNodes counted, creating them now
[0.022213] Adjusting marker info...
[0.022398] Connecting preNodes
[0.026533] Cleaning up memory
[0.026556] Done creating preGraph
[0.026570] Concatenation...
[0.027773] Renumbering preNodes
[0.027804] Initial preNode count 2165
[0.027918] Destroyed 1468 preNodes
[0.027932] Concatenation over!
[0.027941] Clipping short tips off preGraph
[0.028039] Concatenation...
[0.028282] Renumbering preNodes
[0.028299] Initial preNode count 697
[0.028393] Destroyed 204 preNodes
[0.028410] Concatenation over!
[0.028444] 106 tips cut off
[0.028477] 493 nodes left
[0.031932] Writing into pregraph file ./22_33871043_33874754_DEL.6c42ffd2/PreGraph...
[0.038486] Reading read set file ./22_33871043_33874754_DEL.6c42ffd2/Sequences;
[0.039044] 1314 sequences found
[0.042106] Done
[0.046337] Reading pre-graph file ./22_33871043_33874754_DEL.6c42ffd2/PreGraph
[0.046411] Graph has 493 nodes and 1314 sequences
[0.048647] Scanning pre-graph file ./22_33871043_33874754_DEL.6c42ffd2/PreGraph for k-mers
[0.049222] 11319 kmers found
[0.051344] Sorting kmer occurence table ... 
[0.056271] Sorting done.
[0.056291] Computing acceleration table... 
[0.134380] Computing offsets... 
[0.134584] Ghost Threading through reads 0 / 1314
[0.150405]  === Ghost-Threaded in 0.015821 s
[0.150436] Threading through reads 0 / 1314
[0.169132]  === Threaded in 0.018696 s
[0.183975] Correcting graph with cutoff 0.200000
[0.184088] Determining eligible starting points
[0.184726] Done listing starting nodes
[0.184749] Initializing todo lists
[0.184814] Done with initilization
[0.184829] Activating arc lookup table
[0.184887] Done activating arc lookup table
[0.195539] Concatenation...
[0.195590] Renumbering nodes
[0.195600] Initial node count 493
[0.195618] Removed 413 null nodes
[0.195664] Concatenation over!
[0.195674] Clipping short tips off graph, drastic
[0.195692] Concatenation...
[0.195734] Renumbering nodes
[0.195747] Initial node count 80
[0.195757] Removed 0 null nodes
[0.195767] Concatenation over!
[0.195776] 80 nodes left
[0.198166] Writing into graph file ./22_33871043_33874754_DEL.6c42ffd2/Graph2...
[0.203743] Measuring median coverage depth...
[0.203805] Median coverage depth = 32.892105
[0.204589] Removing contigs with coverage < 16.446053...
[0.204638] Concatenation...
[0.204944] Renumbering nodes
[0.204963] Initial node count 80
[0.204975] Removed 77 null nodes
[0.205014] Concatenation over!
[0.205028] Concatenation...
[0.205041] Renumbering nodes
[0.205052] Initial node count 3
[0.205062] Removed 0 null nodes
[0.205104] Concatenation over!
[0.205116] Clipping short tips off graph, drastic
[0.205149] Concatenation...
[0.205160] Renumbering nodes
[0.205170] Initial node count 3
[0.205186] Removed 0 null nodes
[0.205195] Concatenation over!
[0.205231] 3 nodes left
[0.205247] Read coherency...
[0.205257] Identifying unique nodes
[0.205297] Done, 2 unique nodes counted
[0.205312] Trimming read tips
[0.205322] Renumbering nodes
[0.205339] Initial node count 3
[0.205351] Removed 0 null nodes
[0.205362] Confronted to 0 multiple hits and 0 null over 0
[0.205372] Read coherency over!
[0.205414] Starting pebble resolution...
[0.205444] Computing read to node mapping array sizes
[0.205479] Computing read to node mappings
[0.205515] Estimating library insert lengths...
[0.205552] Done
[0.205569] Computing direct node to node mappings
[0.205586] Scaffolding node 0
[0.205680]  === Nodes Scaffolded in 0.000095 s
[0.205718] Preparing to correct graph with cutoff 0.200000
[0.205788] Cleaning memory
[0.205827] Deactivating local correction settings
[0.205852] Pebble done.
[0.205864] Starting pebble resolution...
[0.205908] Computing read to node mapping array sizes
[0.205939] Computing read to node mappings
[0.205970] Estimating library insert lengths...
[0.206009] Done
[0.206026] Computing direct node to node mappings
[0.206036] Scaffolding node 0
[0.206128]  === Nodes Scaffolded in 0.000092 s
[0.206160] Preparing to correct graph with cutoff 0.200000
[0.206218] Cleaning memory
[0.206241] Deactivating local correction settings
[0.206260] Pebble done.
[0.206277] Concatenation...
[0.206288] Renumbering nodes
[0.206302] Initial node count 3
[0.206314] Removed 0 null nodes
[0.206329] Concatenation over!
[0.206351] Removing reference contigs with coverage < 16.446053...
[0.206378] Concatenation...
[0.206391] Renumbering nodes
[0.206417] Initial node count 3
[0.206436] Removed 0 null nodes
[0.206460] Concatenation over!
[0.208964] Writing contigs into ./22_33871043_33874754_DEL.6c42ffd2/contigs.fa...
[0.244002] Writing into stats file ./22_33871043_33874754_DEL.6c42ffd2/stats.txt...
[0.248532] Writing into graph file ./22_33871043_33874754_DEL.6c42ffd2/LastGraph...
[0.252459] Writing into AMOS file ./22_33871043_33874754_DEL.6c42ffd2/velvet_asm.afg...
[0.269286] Printing unused reads into ./22_33871043_33874754_DEL.6c42ffd2/UnusedReads.fa
[0.271469] Estimated Coverage = 32.892105
[0.271495] Estimated Coverage cutoff = 16.446053
Final graph has 3 nodes and n50 of 3824, max 3824, total 4420, using 1261/1314 reads
INFO 2020-05-28 08:10:25,779 22_33871043_33874754_DEL best contig length: 3854
WARNING 2020-05-28 08:10:25,857 22_33871043_33874754_DEL alignstats: []
WARNING 2020-05-28 08:10:25,858 22_33871043_33874754_DEL No good alignment between mutated contig and original, aborting mutation!
WARNING 2020-05-28 08:10:25,858 22_33871043_33874754_DEL best contig did not have sufficent match to reference, aborting mutation.

[adamewing]

Good to see you've got it working. The examples in the docs are intended more as examples of syntax and aren't guaranteed to work across all .bams / reference genomes. The specific error at the end of your output indicates that the assembly for that SV wasn't of sufficient quality which could be for any number of reasons. Getting a specific SV to work can be a bit frustrating. Try a few other sites (maybe check that they're well-covered in your input .bam) and see how you go.

[RichardCorbett]

Thanks. The bams I am hoping to use for this project are only about 30X germline samples. Should that be enough coverage to put SVs into the BAMs? I'm trying a few other coordinates but nothing seems to stick.

[adamewing]

That should be enough. What do your command line arguments look like? Is this Illumina data?

[RichardCorbett]

Hi @adamewing , Yes illumina data - paired-end 150bp.

command: addsv.py -v muts.txt -f /p/B03024_1_lane_dupsFlagged.bam -r /r/hg19a.fa -o test.bam --tmpdir . --debug

muts.txt:

1 16485151 16490151 DEL 1
1 42647192 42657192 DEL 1
1 45013402 45013902 DEL 1
1 47521347 47526347 DEL 1
...

It seems the alignstats report always reports back what looks like an empty list. is it possible the contigs are being made but I'm having trouble aligning them?

Example output:

INFO 2020-05-29 08:12:57,072 1_60382116_60387116_DEL length: 5000
INFO 2020-05-29 08:12:57,231 1_60382116_60387116_DEL discordant fraction: 0.004019
INFO 2020-05-29 08:13:33,731 found mates for 1000 reads, 0.00 discordant.
INFO 2020-05-29 08:13:41,869 found 1241 reads in region.
[0.000000] Reading FastA file ./1_60382116_60387116_DEL.tmpreads.a26e72bd-c7bb-41eb-b7b1-53d11d7a4d95.fasta;
[0.006623] 1326 sequences found
[0.006644] Done
[0.009115] Reading read set file ./1_60382116_60387116_DEL.588fb930/Sequences;
[0.012085] 1326 sequences found
[0.015529] Done
[0.015567] 1326 sequences in total.
[0.038896] Writing into roadmap file ./1_60382116_60387116_DEL.588fb930/Roadmaps...
[0.042476] Inputting sequences...
[0.042500] Inputting sequence 0 / 1326
[0.127940]  === Sequences loaded in 0.085465 s
[0.130018] Done inputting sequences
[0.130039] Destroying splay table
[0.141840] Splay table destroyed
[0.000000] Reading roadmap file ./1_60382116_60387116_DEL.588fb930/Roadmaps
[0.006365] 1326 roadmaps read
[0.006430] Creating insertion markers
[0.006734] Ordering insertion markers
[0.009686] Counting preNodes
[0.009992] 2055 preNodes counted, creating them now
[0.020989] Adjusting marker info...
[0.021151] Connecting preNodes
[0.025101] Cleaning up memory
[0.025130] Done creating preGraph
[0.025153] Concatenation...
[0.026274] Renumbering preNodes
[0.026295] Initial preNode count 2055
[0.026400] Destroyed 1406 preNodes
[0.026422] Concatenation over!
[0.026458] Clipping short tips off preGraph
[0.026593] Concatenation...
[0.026861] Renumbering preNodes
[0.026878] Initial preNode count 649
[0.026935] Destroyed 230 preNodes
[0.026962] Concatenation over!
[0.026981] 118 tips cut off
[0.026994] 419 nodes left
[0.028494] Writing into pregraph file ./1_60382116_60387116_DEL.588fb930/PreGraph...
[0.033148] Reading read set file ./1_60382116_60387116_DEL.588fb930/Sequences;
[0.033687] 1326 sequences found
[0.036509] Done
[0.041292] Reading pre-graph file ./1_60382116_60387116_DEL.588fb930/PreGraph
[0.041351] Graph has 419 nodes and 1326 sequences
[0.043081] Scanning pre-graph file ./1_60382116_60387116_DEL.588fb930/PreGraph for k-mers
[0.043590] 10980 kmers found
[0.045449] Sorting kmer occurence table ... 
[0.050154] Sorting done.
[0.050173] Computing acceleration table... 
[0.127696] Computing offsets... 
[0.127877] Ghost Threading through reads 0 / 1326
[0.143730]  === Ghost-Threaded in 0.015853 s
[0.143756] Threading through reads 0 / 1326
[0.161572]  === Threaded in 0.017816 s
[0.173444] Correcting graph with cutoff 0.200000
[0.173522] Determining eligible starting points
[0.173809] Done listing starting nodes
[0.173823] Initializing todo lists
[0.173881] Done with initilization
[0.173890] Activating arc lookup table
[0.173934] Done activating arc lookup table
[0.178252] Concatenation...
[0.178280] Renumbering nodes
[0.178285] Initial node count 419
[0.178294] Removed 362 null nodes
[0.178299] Concatenation over!
[0.178304] Clipping short tips off graph, drastic
[0.178315] Concatenation...
[0.178321] Renumbering nodes
[0.178326] Initial node count 57
[0.178372] Removed 0 null nodes
[0.178381] Concatenation over!
[0.178386] 57 nodes left
[0.180077] Writing into graph file ./1_60382116_60387116_DEL.588fb930/Graph2...
[0.183361] Measuring median coverage depth...
[0.183392] Median coverage depth = 28.154286
[0.183893] Removing contigs with coverage < 14.077143...
[0.183922] Concatenation...
[0.184074] Renumbering nodes
[0.184087] Initial node count 57
[0.184118] Removed 56 null nodes
[0.184123] Concatenation over!
[0.184131] Concatenation...
[0.184135] Renumbering nodes
[0.184159] Initial node count 1
[0.184165] Removed 0 null nodes
[0.184172] Concatenation over!
[0.184178] Clipping short tips off graph, drastic
[0.184183] Concatenation...
[0.184207] Renumbering nodes
[0.184213] Initial node count 1
[0.184220] Removed 0 null nodes
[0.184225] Concatenation over!
[0.184230] 1 nodes left
[0.184255] Read coherency...
[0.184261] Identifying unique nodes
[0.184268] Done, 1 unique nodes counted
[0.184274] Trimming read tips
[0.184279] Renumbering nodes
[0.184292] Initial node count 1
[0.184299] Removed 0 null nodes
[0.184306] Confronted to 0 multiple hits and 0 null over 0
[0.184315] Read coherency over!
[0.184345] Starting pebble resolution...
[0.184371] Computing read to node mapping array sizes
[0.184390] Computing read to node mappings
[0.184408] Estimating library insert lengths...
[0.184428] Done
[0.184437] Computing direct node to node mappings
[0.184447] Scaffolding node 0
[0.184486]  === Nodes Scaffolded in 0.000039 s
[0.184508] Preparing to correct graph with cutoff 0.200000
[0.184552] Cleaning memory
[0.184572] Deactivating local correction settings
[0.184587] Pebble done.
[0.184594] Starting pebble resolution...
[0.184607] Computing read to node mapping array sizes
[0.184627] Computing read to node mappings
[0.184643] Estimating library insert lengths...
[0.184664] Done
[0.184672] Computing direct node to node mappings
[0.184678] Scaffolding node 0
[0.184715]  === Nodes Scaffolded in 0.000038 s
[0.184729] Preparing to correct graph with cutoff 0.200000
[0.184759] Cleaning memory
[0.184768] Deactivating local correction settings
[0.184781] Pebble done.
[0.184790] Concatenation...
[0.184796] Renumbering nodes
[0.184801] Initial node count 1
[0.184809] Removed 0 null nodes
[0.184814] Concatenation over!
[0.184821] Removing reference contigs with coverage < 14.077143...
[0.184829] Concatenation...
[0.184833] Renumbering nodes
[0.184838] Initial node count 1
[0.184846] Removed 0 null nodes
[0.184850] Concatenation over!
[0.186522] Writing contigs into ./1_60382116_60387116_DEL.588fb930/contigs.fa...
[0.190186] Writing into stats file ./1_60382116_60387116_DEL.588fb930/stats.txt...
[0.193918] Writing into graph file ./1_60382116_60387116_DEL.588fb930/LastGraph...
[0.196302] Writing into AMOS file ./1_60382116_60387116_DEL.588fb930/velvet_asm.afg...
[0.207156] Printing unused reads into ./1_60382116_60387116_DEL.588fb930/UnusedReads.fa
[0.209125] Estimated Coverage = 28.154286
[0.209150] Estimated Coverage cutoff = 14.077143
Final graph has 1 nodes and n50 of 4179, max 4179, total 4179, using 1244/1326 reads
INFO 2020-05-29 08:13:42,456 1_60382116_60387116_DEL best contig length: 4209
WARNING 2020-05-29 08:13:42,492 1_60382116_60387116_DEL alignstats: []
WARNING 2020-05-29 08:13:42,493 1_60382116_60387116_DEL No good alignment between mutated contig and original, aborting mutation!
WARNING 2020-05-29 08:13:42,493 1_60382116_60387116_DEL best contig did not have sufficent match to reference, aborting mutation.

.stats file:

ID  lgth    out in  long_cov    short1_cov  short1_Ocov short2_cov  short2_Ocov long_nb short1_nb   short2_nb
1   4179    0   0   0.000000    33.631730   32.482651   0.000000    0.000000    0   1244    0

[adamewing]

Hmm, could be. Can you run python setup.py install without errors? (this checks for exonerate which is the relevant aligner here) Second, if you run the sv test in test/test_sv.sh do you see similar warning messages?

[adamewing]

The other thing I'm wondering is whether "--tmpdir ." is causing a problem, could you try setting the path explicitly if the above suggestions don't yield anything?

[RichardCorbett]

Hi @adamewing, Thanks for continuing to work on this.

By my eye it looks as though the installation and tests run successfully, and switching the --tmpdir to a full path doesn't change my test results. Do you think it is possible that the issue might be related to my bam files? They are germline genomes aligned with minimap2 and sorted and dupmarked with sambamba.

I feel like we we're close on this.

python3 setup.py install
running install
running bdist_egg
running egg_info
creating bamsurgeon.egg-info
writing bamsurgeon.egg-info/PKG-INFO
writing dependency_links to bamsurgeon.egg-info/dependency_links.txt
writing requirements to bamsurgeon.egg-info/requires.txt
writing top-level names to bamsurgeon.egg-info/top_level.txt
writing manifest file 'bamsurgeon.egg-info/SOURCES.txt'
reading manifest file 'bamsurgeon.egg-info/SOURCES.txt'
writing manifest file 'bamsurgeon.egg-info/SOURCES.txt'
installing library code to build/bdist.linux-x86_64/egg
running install_lib
running build_py
creating build
creating build/lib
creating build/lib/bamsurgeon
copying bamsurgeon/markreads.py -> build/lib/bamsurgeon
copying bamsurgeon/common.py -> build/lib/bamsurgeon
copying bamsurgeon/replacereads.py -> build/lib/bamsurgeon
copying bamsurgeon/makevcf.py -> build/lib/bamsurgeon
copying bamsurgeon/asmregion.py -> build/lib/bamsurgeon
copying bamsurgeon/mutation.py -> build/lib/bamsurgeon
copying bamsurgeon/mutableseq.py -> build/lib/bamsurgeon
copying bamsurgeon/parseamos.py -> build/lib/bamsurgeon
copying bamsurgeon/__init__.py -> build/lib/bamsurgeon
copying bamsurgeon/aligners.py -> build/lib/bamsurgeon
creating build/bdist.linux-x86_64
creating build/bdist.linux-x86_64/egg
creating build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/markreads.py -> build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/common.py -> build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/replacereads.py -> build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/makevcf.py -> build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/asmregion.py -> build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/mutation.py -> build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/mutableseq.py -> build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/parseamos.py -> build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/__init__.py -> build/bdist.linux-x86_64/egg/bamsurgeon
copying build/lib/bamsurgeon/aligners.py -> build/bdist.linux-x86_64/egg/bamsurgeon
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/markreads.py to markreads.cpython-36.pyc
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/common.py to common.cpython-36.pyc
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/replacereads.py to replacereads.cpython-36.pyc
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/makevcf.py to makevcf.cpython-36.pyc
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/asmregion.py to asmregion.cpython-36.pyc
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/mutation.py to mutation.cpython-36.pyc
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/mutableseq.py to mutableseq.cpython-36.pyc
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/parseamos.py to parseamos.cpython-36.pyc
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/__init__.py to __init__.cpython-36.pyc
byte-compiling build/bdist.linux-x86_64/egg/bamsurgeon/aligners.py to aligners.cpython-36.pyc
creating build/bdist.linux-x86_64/egg/EGG-INFO
installing scripts to build/bdist.linux-x86_64/egg/EGG-INFO/scripts
running install_scripts
running build_scripts
creating build/scripts-3.6
copying and adjusting bin/addindel.py -> build/scripts-3.6
copying and adjusting bin/addsnv.py -> build/scripts-3.6
copying and adjusting bin/addsv.py -> build/scripts-3.6
copying and adjusting scripts/bamregions_from_vcf.py -> build/scripts-3.6
copying and adjusting scripts/bamsplit.py -> build/scripts-3.6
copying and adjusting scripts/bamsplit_proportion.py -> build/scripts-3.6
copying and adjusting scripts/bamsplit_multiple.py -> build/scripts-3.6
copying and adjusting scripts/bsrg.py -> build/scripts-3.6
copying and adjusting scripts/covered_segments.py -> build/scripts-3.6
copying and adjusting scripts/dedup.py -> build/scripts-3.6
copying and adjusting scripts/evaluator.py -> build/scripts-3.6
copying and adjusting scripts/makevcf.py -> build/scripts-3.6
copying and adjusting scripts/makevcf_indels.py -> build/scripts-3.6
copying and adjusting scripts/makevcf_sv.py -> build/scripts-3.6
copying and adjusting scripts/postprocess.py -> build/scripts-3.6
copying and adjusting scripts/randomsites.py -> build/scripts-3.6
copying and adjusting scripts/remove_unpaired.py -> build/scripts-3.6
copying and adjusting scripts/rename_reads.py -> build/scripts-3.6
copying and adjusting scripts/seperation.py -> build/scripts-3.6
copying and adjusting scripts/match_fasta_to_bam.py -> build/scripts-3.6
changing mode of build/scripts-3.6/addindel.py from 664 to 775
changing mode of build/scripts-3.6/addsnv.py from 664 to 775
changing mode of build/scripts-3.6/addsv.py from 664 to 775
changing mode of build/scripts-3.6/bamregions_from_vcf.py from 664 to 775
changing mode of build/scripts-3.6/bamsplit.py from 664 to 775
changing mode of build/scripts-3.6/bamsplit_proportion.py from 664 to 775
changing mode of build/scripts-3.6/bamsplit_multiple.py from 664 to 775
changing mode of build/scripts-3.6/bsrg.py from 664 to 775
changing mode of build/scripts-3.6/covered_segments.py from 664 to 775
changing mode of build/scripts-3.6/dedup.py from 664 to 775
changing mode of build/scripts-3.6/evaluator.py from 664 to 775
changing mode of build/scripts-3.6/makevcf.py from 664 to 775
changing mode of build/scripts-3.6/makevcf_indels.py from 664 to 775
changing mode of build/scripts-3.6/makevcf_sv.py from 664 to 775
changing mode of build/scripts-3.6/postprocess.py from 664 to 775
changing mode of build/scripts-3.6/randomsites.py from 664 to 775
changing mode of build/scripts-3.6/remove_unpaired.py from 664 to 775
changing mode of build/scripts-3.6/rename_reads.py from 664 to 775
changing mode of build/scripts-3.6/seperation.py from 664 to 775
changing mode of build/scripts-3.6/match_fasta_to_bam.py from 664 to 775
creating build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/randomsites.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/seperation.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/remove_unpaired.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/evaluator.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/addsv.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/dedup.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/addindel.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/postprocess.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/covered_segments.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/makevcf.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/bamsplit.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/bamregions_from_vcf.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/rename_reads.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/bsrg.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/addsnv.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/makevcf_indels.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/bamsplit_multiple.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/makevcf_sv.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/bamsplit_proportion.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
copying build/scripts-3.6/match_fasta_to_bam.py -> build/bdist.linux-x86_64/egg/EGG-INFO/scripts
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/randomsites.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/seperation.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/remove_unpaired.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/evaluator.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/addsv.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/dedup.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/addindel.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/postprocess.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/covered_segments.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/makevcf.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/bamsplit.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/bamregions_from_vcf.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/rename_reads.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/bsrg.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/addsnv.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/makevcf_indels.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/bamsplit_multiple.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/makevcf_sv.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/bamsplit_proportion.py to 775
changing mode of build/bdist.linux-x86_64/egg/EGG-INFO/scripts/match_fasta_to_bam.py to 775
copying bamsurgeon.egg-info/PKG-INFO -> build/bdist.linux-x86_64/egg/EGG-INFO
copying bamsurgeon.egg-info/SOURCES.txt -> build/bdist.linux-x86_64/egg/EGG-INFO
copying bamsurgeon.egg-info/dependency_links.txt -> build/bdist.linux-x86_64/egg/EGG-INFO
copying bamsurgeon.egg-info/requires.txt -> build/bdist.linux-x86_64/egg/EGG-INFO
copying bamsurgeon.egg-info/top_level.txt -> build/bdist.linux-x86_64/egg/EGG-INFO
zip_safe flag not set; analyzing archive contents...
creating dist
creating 'dist/bamsurgeon-1.2-py3.6.egg' and adding 'build/bdist.linux-x86_64/egg' to it
removing 'build/bdist.linux-x86_64/egg' (and everything under it)
Processing bamsurgeon-1.2-py3.6.egg
Copying bamsurgeon-1.2-py3.6.egg to /usr/local/lib/python3.6/site-packages
Adding bamsurgeon 1.2 to easy-install.pth file
Installing addindel.py script to /usr/local/bin
Installing addsnv.py script to /usr/local/bin
Installing addsv.py script to /usr/local/bin
Installing bamregions_from_vcf.py script to /usr/local/bin
Installing bamsplit.py script to /usr/local/bin
Installing bamsplit_multiple.py script to /usr/local/bin
Installing bamsplit_proportion.py script to /usr/local/bin
Installing bsrg.py script to /usr/local/bin
Installing covered_segments.py script to /usr/local/bin
Installing dedup.py script to /usr/local/bin
Installing evaluator.py script to /usr/local/bin
Installing makevcf.py script to /usr/local/bin
Installing makevcf_indels.py script to /usr/local/bin
Installing makevcf_sv.py script to /usr/local/bin
Installing match_fasta_to_bam.py script to /usr/local/bin
Installing postprocess.py script to /usr/local/bin
Installing randomsites.py script to /usr/local/bin
Installing remove_unpaired.py script to /usr/local/bin
Installing rename_reads.py script to /usr/local/bin
Installing seperation.py script to /usr/local/bin

Installed /usr/local/lib/python3.6/site-packages/bamsurgeon-1.2-py3.6.egg
Processing dependencies for bamsurgeon==1.2
Searching for PyVCF
Reading https://pypi.org/simple/PyVCF/
Downloading https://files.pythonhosted.org/packages/20/b6/36bfb1760f6983788d916096193fc14c83cce512c7787c93380e09458c09/PyVCF-0.6.8.tar.gz#sha256=e9d872513d179d229ab61da47a33f42726e9613784d1cb2bac3f8e2642f6f9d9
Best match: PyVCF 0.6.8
Processing PyVCF-0.6.8.tar.gz
Writing /tmp/easy_install-5e85a3by/PyVCF-0.6.8/setup.cfg
Running PyVCF-0.6.8/setup.py -q bdist_egg --dist-dir /tmp/easy_install-5e85a3by/PyVCF-0.6.8/egg-dist-tmp-4vjq7x20
/usr/local/lib64/python3.6/site-packages/Cython/Compiler/Main.py:369: FutureWarning: Cython directive 'language_level' not set, using 2 for now (Py2). This will change in a later release! File: /tmp/easy_install-5e85a3by/PyVCF-0.6.8/vcf/cparse.pyx
  tree = Parsing.p_module(s, pxd, full_module_name)
warning: vcf/cparse.pyx:16:14: Non-trivial type declarators in shared declaration (e.g. mix of pointers and values). Each pointer declaration should be on its own line.
warning: vcf/cparse.pyx:16:21: Non-trivial type declarators in shared declaration (e.g. mix of pointers and values). Each pointer declaration should be on its own line.
warning: vcf/cparse.pyx:16:27: Non-trivial type declarators in shared declaration (e.g. mix of pointers and values). Each pointer declaration should be on its own line.
warning: vcf/cparse.pyx:16:40: Non-trivial type declarators in shared declaration (e.g. mix of pointers and values). Each pointer declaration should be on its own line.
zip_safe flag not set; analyzing archive contents...
vcf.__pycache__.cparse.cpython-36: module references __file__
vcf.test.__pycache__.test_vcf.cpython-36: module references __file__
creating /usr/local/lib/python3.6/site-packages/PyVCF-0.6.8-py3.6-linux-x86_64.egg
Extracting PyVCF-0.6.8-py3.6-linux-x86_64.egg to /usr/local/lib/python3.6/site-packages
Adding PyVCF 0.6.8 to easy-install.pth file
Installing vcf_melt script to /usr/local/bin
Installing vcf_filter.py script to /usr/local/bin
Installing vcf_sample_filter.py script to /usr/local/bin

Installed /usr/local/lib/python3.6/site-packages/PyVCF-0.6.8-py3.6-linux-x86_64.egg
Searching for pysam==0.15.4
Best match: pysam 0.15.4
Adding pysam 0.15.4 to easy-install.pth file

Using /usr/local/lib64/python3.6/site-packages
Searching for setuptools==39.2.0
Best match: setuptools 39.2.0
Adding setuptools 39.2.0 to easy-install.pth file
Installing easy_install script to /usr/local/bin
Installing easy_install-3.6 script to /usr/local/bin

Using /usr/lib/python3.6/site-packages
Finished processing dependencies for bamsurgeon==1.2

When I try and run the test/test_sv.sh I think everything is working fine. Here's some of the output:

+ ./test_sv.sh
INFO 2020-05-30 23:46:35,723 starting /usr/local/bin/addsv.py called with args: /usr/local/bin/addsv.py -p 1 -v ../test_data/test_sv.txt -f ../test_data/testregion_realign.bam -r ../test_data/Homo_sapiens_chr22_assembly19.fasta -o ../test_data/testregion_sv_mut.bam --aligner mem --keepsecondary --seed 1234 --inslib ../test_data/test_inslib.fa
INFO 2020-05-30 23:46:35,724 loading insertion library from ../test_data/test_inslib.fa
INFO 2020-05-30 23:46:35,732 created tmp directory: addsv.tmp
INFO 2020-05-30 23:46:35,733 created log directory: addsv_logs_testregion_sv_mut.bam
WARNING 2020-05-30 23:46:35,734 22 33871043 33884754 DEL 0.75 is over 10kbp long: converting to use BIGDEL instead.
WARNING 2020-05-30 23:46:35,735 22 34071043 34084754 INV 0.5 is over 10kbp long: converting to use BIGINV instead.
WARNING 2020-05-30 23:46:35,735 22 34271043 34284754 DUP 3 0.9 is over 10kbp long: converting to use BIGDUP instead.
WARNING 2020-05-30 23:46:35,735 22 34271043 34284754 DUP 0.9: using BIGDUP requires specifying a --donorbam and none was provided, using ../test_data/testregion_realign.bam
INFO 2020-05-30 23:46:35,738 22_33609508_33611508_INS interval: 22 33609508 33611508 INS INSLIB:10_9258941_9259251_AluYa5_+ 8
INFO 2020-05-30 23:46:35,738 22_33609508_33611508_INS length: 2000
INFO 2020-05-30 23:46:35,752 22_33609508_33611508_INS discordant fraction: 0.000000
INFO 2020-05-30 23:46:39,523 found mates for 1000 reads, 0.00 discordant.
INFO 2020-05-30 23:46:43,986 found mates for 2000 reads, 0.00 discordant.
INFO 2020-05-30 23:46:45,490 found 2301 reads in region.
[0.000000] Reading FastA file addsv.tmp/22_33609508_33611508_INS.tmpreads.798b6dd7-f1f6-4ac6-b8dc-ecb45abde7e9.fasta;
[0.004674] 2550 sequences found
[0.004690] Done
[0.004723] Reading read set file addsv.tmp/22_33609508_33611508_INS.75c86cc0/Sequences;
[0.005123] 2550 sequences found
[0.007376] Done
[0.007392] 2550 sequences in total.
[0.007415] Writing into roadmap file addsv.tmp/22_33609508_33611508_INS.75c86cc0/Roadmaps...
[0.009826] Inputting sequences...
[0.009843] Inputting sequence 0 / 2550
[0.035776]  === Sequences loaded in 0.025950 s
[0.035835] Done inputting sequences
[0.035844] Destroying splay table
[0.037640] Splay table destroyed
[0.000000] Reading roadmap file addsv.tmp/22_33609508_33611508_INS.75c86cc0/Roadmaps
[0.005623] 2550 roadmaps read
[0.005651] Creating insertion markers
[0.005951] Ordering insertion markers
[0.007931] Counting preNodes
[0.008167] 3173 preNodes counted, creating them now
[0.014799] Adjusting marker info...
[0.014974] Connecting preNodes
[0.018501] Cleaning up memory
[0.018535] Done creating preGraph
[0.018546] Concatenation...
[0.019155] Renumbering preNodes
[0.019169] Initial preNode count 3173
[0.019184] Destroyed 3172 preNodes
[0.019191] Concatenation over!
[0.019197] Clipping short tips off preGraph
[0.019204] Concatenation...
[0.019210] Renumbering preNodes
[0.019216] Initial preNode count 1
[0.019223] Destroyed 0 preNodes
[0.019268] Concatenation over!
[0.019297] 0 tips cut off
[0.019322] 1 nodes left
[0.019361] Writing into pregraph file addsv.tmp/22_33609508_33611508_INS.75c86cc0/PreGraph...
[0.019653] Reading read set file addsv.tmp/22_33609508_33611508_INS.75c86cc0/Sequences;
[0.020043] 2550 sequences found
[0.022164] Done
[0.024473] Reading pre-graph file addsv.tmp/22_33609508_33611508_INS.75c86cc0/PreGraph
[0.024501] Graph has 1 nodes and 2550 sequences
[0.024629] Scanning pre-graph file addsv.tmp/22_33609508_33611508_INS.75c86cc0/PreGraph for k-mers
[0.024693] 5171 kmers found
[0.024895] Sorting kmer occurence table ... 
[0.025735] Sorting done.
[0.025748] Computing acceleration table... 
[0.059630] Computing offsets... 
[0.059705] Ghost Threading through reads 0 / 2550
[0.066856]  === Ghost-Threaded in 0.007151 s
[0.066873] Threading through reads 0 / 2550
[0.074766]  === Threaded in 0.007893 s
[0.078874] Correcting graph with cutoff 0.200000
[0.078916] Determining eligible starting points
[0.078948] Done listing starting nodes
[0.078957] Initializing todo lists
[0.078976] Done with initilization
[0.078983] Activating arc lookup table
[0.079032] Done activating arc lookup table
[0.079049] Concatenation...
[0.079071] Renumbering nodes
[0.079081] Initial node count 1
[0.079093] Removed 0 null nodes
[0.079116] Concatenation over!
[0.079147] Clipping short tips off graph, drastic
[0.079160] Concatenation...
[0.079178] Renumbering nodes
[0.079184] Initial node count 1
[0.079195] Removed 0 null nodes
[0.079217] Concatenation over!
[0.079232] 1 nodes left
[0.079291] Writing into graph file addsv.tmp/22_33609508_33611508_INS.75c86cc0/Graph2...
[0.080431] Measuring median coverage depth...
[0.080447] Median coverage depth = 34.516148
[0.080480] Removing contigs with coverage < 17.258074...
[0.080493] Concatenation...
[0.080544] Renumbering nodes
[0.080556] Initial node count 1
[0.080564] Removed 0 null nodes
[0.080577] Concatenation over!
[0.080592] Concatenation...
[0.080601] Renumbering nodes
[0.080630] Initial node count 1
[0.080647] Removed 0 null nodes
[0.080655] Concatenation over!
[0.080666] Clipping short tips off graph, drastic
[0.080675] Concatenation...
[0.080690] Renumbering nodes
[0.080700] Initial node count 1
[0.080713] Removed 0 null nodes
[0.080722] Concatenation over!
[0.080728] 1 nodes left
[0.080749] Read coherency...
[0.080761] Identifying unique nodes
[0.080775] Done, 1 unique nodes counted
[0.080785] Trimming read tips
[0.080794] Renumbering nodes
[0.080803] Initial node count 1
[0.080820] Removed 0 null nodes
[0.080834] Confronted to 0 multiple hits and 0 null over 0
[0.080844] Read coherency over!
[0.080880] Starting pebble resolution...
[0.080904] Computing read to node mapping array sizes
[0.080934] Computing read to node mappings
[0.080966] Estimating library insert lengths...
[0.080997] Done
[0.081018] Computing direct node to node mappings
[0.081034] Scaffolding node 0
[0.081107]  === Nodes Scaffolded in 0.000073 s
[0.081141] Preparing to correct graph with cutoff 0.200000
[0.081188] Cleaning memory
[0.081210] Deactivating local correction settings
[0.081228] Pebble done.
[0.081245] Starting pebble resolution...
[0.081264] Computing read to node mapping array sizes
[0.081293] Computing read to node mappings
[0.081323] Estimating library insert lengths...
[0.081362] Done
[0.081373] Computing direct node to node mappings
[0.081389] Scaffolding node 0
[0.081458]  === Nodes Scaffolded in 0.000069 s
[0.081483] Preparing to correct graph with cutoff 0.200000
[0.081509] Cleaning memory
[0.081521] Deactivating local correction settings
[0.081540] Pebble done.
[0.081554] Concatenation...
[0.081567] Renumbering nodes
[0.081575] Initial node count 1
[0.081582] Removed 0 null nodes
[0.081593] Concatenation over!
[0.081610] Removing reference contigs with coverage < 17.258074...
[0.081630] Concatenation...
[0.081639] Renumbering nodes
[0.081651] Initial node count 1
[0.081661] Removed 0 null nodes
[0.081679] Concatenation over!
[0.081718] Writing contigs into addsv.tmp/22_33609508_33611508_INS.75c86cc0/contigs.fa...
[0.082467] Writing into stats file addsv.tmp/22_33609508_33611508_INS.75c86cc0/stats.txt...
[0.082540] Writing into graph file addsv.tmp/22_33609508_33611508_INS.75c86cc0/LastGraph...
[0.083640] Writing into AMOS file addsv.tmp/22_33609508_33611508_INS.75c86cc0/velvet_asm.afg...
[0.089358] Printing unused reads into addsv.tmp/22_33609508_33611508_INS.75c86cc0/UnusedReads.fa
[0.089394] Estimated Coverage = 34.516148
[0.089407] Estimated Coverage cutoff = 17.258074
Final graph has 1 nodes and n50 of 5171, max 5171, total 5171, using 2550/2550 reads
INFO 2020-05-30 23:46:45,811 22_33609508_33611508_INS best contig length: 5201
INFO 2020-05-30 23:46:45,837 22_33609508_33611508_INS alignment result: ['SUMMARY', '20000', '617', '4617', '0', '4000']
INFO 2020-05-30 23:46:45,842 22_33609508_33611508_INS trimmed contig length: 4000
INFO 2020-05-30 23:46:45,842 22_33609508_33611508_INS start: 33608508, end: 33612508, tgtstart: 0, tgtend: 4000, refstart: 33608508, refend: 33612508
INFO 2020-05-30 23:46:45,842 22_33609508_33611508_INS action: INS INSLIB:10_9258941_9259251_AluYa5_+ 8 INS
INFO 2020-05-30 23:46:45,842 22_33609508_33611508_INS final VAF accounting for copy number 1.000000: 1.000000
INFO 2020-05-30 23:46:45,842 22_33609508_33611508_INS specify sequence from insertion library: 10_9258941_9259251_AluYa5_+
INFO 2020-05-30 23:46:45,843 22_33609508_33611508_INS set paired end mean distance: 300.000000
INFO 2020-05-30 23:46:45,843 22_33609508_33611508_INS set paired end distance stddev: 70.000000
INFO 2020-05-30 23:46:45,845 22_33609508_33611508_INS paired reads: 997
INFO 2020-05-30 23:46:45,845 22_33609508_33611508_INS single reads: 246
INFO 2020-05-30 23:46:45,845 22_33609508_33611508_INS discard reads: 0
INFO 2020-05-30 23:46:45,845 22_33609508_33611508_INS total reads: 2240
INFO 2020-05-30 23:46:45,845 22_33609508_33611508_INS old ctg len: 4000
INFO 2020-05-30 23:46:45,845 22_33609508_33611508_INS new ctg len: 4318
INFO 2020-05-30 23:46:45,846 22_33609508_33611508_INS adj. factor: 1.079500
INFO 2020-05-30 23:46:45,846 22_33609508_33611508_INS num. sim. reads: 1209
INFO 2020-05-30 23:46:45,846 22_33609508_33611508_INS PE mean outer distance: 300.000000
INFO 2020-05-30 23:46:45,846 22_33609508_33611508_INS PE outer distance SD: 70.000000
INFO 2020-05-30 23:46:45,846 22_33609508_33611508_INS rerror rate: 0.000000
INFO 2020-05-30 23:46:45,847 ['wgsim', '-e', '0.0', '-d', '300.0', '-s', '70.0', '-N', '1209', '-1', '100', '-2', '100', '-r', '0', '-R', '0', 'addsv.tmp/22_33609508_33611508_INS.wgsimtmp.311036f1-b499-41e1-a16a-7c02c3475701.fasta', 'addsv.tmp/22_33609508_33611508_INS.wgsimtmp.311036f1-b499-41e1-a16a-7c02c3475701.1.fq', 'addsv.tmp/22_33609508_33611508_INS.wgsimtmp.311036f1-b499-41e1-a16a-7c02c3475701.2.fq', '-S', '1234']
[wgsim] seed = 1234
[wgsim_core] calculating the total length of the reference sequence...
[wgsim_core] 1 sequences, total length: 4318
INFO 2020-05-30 23:46:45,888 22_33609508_33611508_INS aligning addsv.tmp/22_33609508_33611508_INS.wgsimtmp.311036f1-b499-41e1-a16a-7c02c3475701.1.fq,addsv.tmp/22_33609508_33611508_INS.wgsimtmp.311036f1-b499-41e1-a16a-7c02c3475701.2.fq with bwa mem
[M::bwa_idx_load_from_disk] read 0 ALT contigs
[M::process] read 2418 sequences (241800 bp)...
[M::mem_pestat] # candidate unique pairs for (FF, FR, RF, RR): (0, 1035, 0, 0)
[M::mem_pestat] skip orientation FF as there are not enough pairs
[M::mem_pestat] analyzing insert size distribution for orientation FR...
[M::mem_pestat] (25, 50, 75) percentile: (247, 299, 350)
[M::mem_pestat] low and high boundaries for computing mean and std.dev: (41, 556)
[M::mem_pestat] mean and std.dev: (297.37, 72.37)
[M::mem_pestat] low and high boundaries for proper pairs: (1, 659)
[M::mem_pestat] skip orientation RF as there are not enough pairs
[M::mem_pestat] skip orientation RR as there are not enough pairs
[M::mem_process_seqs] Processed 2418 reads in 0.374 CPU sec, 0.373 real sec
[main] Version: 0.7.17-r1198-dirty
[main] CMD: bwa mem -t 1 -M -Y ../test_data/Homo_sapiens_chr22_assembly19.fasta addsv.tmp/22_33609508_33611508_INS.wgsimtmp.311036f1-b499-41e1-a16a-7c02c3475701.1.fq addsv.tmp/22_33609508_33611508_INS.wgsimtmp.311036f1-b499-41e1-a16a-7c02c3475701.2.fq
[main] Real time: 0.460 sec; CPU: 0.455 sec
INFO 2020-05-30 23:46:46,351 22_33609508_33611508_INS writing bwatmp.d56c3fb9-78b7-40c4-9413-c07b81eebde2.sam to BAM...
INFO 2020-05-30 23:46:46,389 22_33609508_33611508_INS deleting SAM: bwatmp.d56c3fb9-78b7-40c4-9413-c07b81eebde2.sam
INFO 2020-05-30 23:46:46,390 22_33609508_33611508_INS sorting output: samtools sort -@ 1 -T bwatmp.d56c3fb9-78b7-40c4-9413-c07b81eebde2.sorted.bam -o bwatmp.d56c3fb9-78b7-40c4-9413-c07b81eebde2.sorted.bam addsv.tmp/22_33609508_33611508_INS.6570ff22-1507-4449-bfcc-69de9ea6e3a3.muts.bam
INFO 2020-05-30 23:46:46,420 22_33609508_33611508_INS remove original bam:addsv.tmp/22_33609508_33611508_INS.6570ff22-1507-4449-bfcc-69de9ea6e3a3.muts.bam
INFO 2020-05-30 23:46:46,421 22_33609508_33611508_INS rename sorted bam: bwatmp.d56c3fb9-78b7-40c4-9413-c07b81eebde2.sorted.bam to original name: addsv.tmp/22_33609508_33611508_INS.6570ff22-1507-4449-bfcc-69de9ea6e3a3.muts.bam
INFO 2020-05-30 23:46:46,422 22_33609508_33611508_INS indexing: samtools index addsv.tmp/22_33609508_33611508_INS.6570ff22-1507-4449-bfcc-69de9ea6e3a3.muts.bam
INFO 2020-05-30 23:46:46,432 22_33609508_33611508_INS removing addsv.tmp/22_33609508_33611508_INS.wgsimtmp.311036f1-b499-41e1-a16a-7c02c3475701.1.fq
INFO 2020-05-30 23:46:46,432 22_33609508_33611508_INS removing addsv.tmp/22_33609508_33611508_INS.wgsimtmp.311036f1-b499-41e1-a16a-7c02c3475701.2.fq
INFO 2020-05-30 23:46:46,433 22_33609508_33611508_INS temporary bam: addsv.tmp/22_33609508_33611508_INS.6570ff22-1507-4449-bfcc-69de9ea6e3a3.muts.bam

[RichardCorbett]

I don't think it is a minimap issue. If I copy the test data out of my container I still get the same issue as above. I was able to compare the complete output and the first difference between the successful and unsuccessful run is the line that contains "alignstats: []" in the unsuccessful run.

When I use setup.py for bamsurgeon the addsv.py command goes to /usr/local/bin/. Do any of the other binaries need to be there, or is having them in the $PATH sufficient?

[RichardCorbett]

Got it.

The exonerate command is trying to write to the folder in my environment defined by $TMPDIR, but I needed to bind that folder during my container start up commands. Somewhere in addsv.py there is probably a permission error that doesn't float the the surface.

[adamewing]

Ah, yes, good to know. Exonerate doesn't seem to accept a parameter to relocate the temporary directory unfortunately but can try to generate an error if $TMPDIR isn't accessible to addsv.