[1469553750] Using temporary directory tmp_yeNQXV
[1469553750] Cropping unmapped reads from test.bam
[1469553755] Map of low quality mates has 1 records.
[1469553757] Unmapped reads written to ./paired.1.fastq, ./paired.2.fastq, ./single.fastq
[1469553758] Mapped mates of unmapped reads written to tmp_yeNQXV/mates.bam , 0 found in second pass
[1469553758] Sorting tmp_yeNQXV/mates.bam using /usr/local/apps/popins/05b1dd1/samtools-1.0/samtools
[1469553758] Filtering fastq files using /usr/local/apps/popins/05b1dd1/sickle-1.20/sickle

FastQ paired records kept: 0 (0 pairs)
FastQ single records kept: 0 (from PE1: 0, from PE2: 0)
FastQ paired records discarded: 0 (0 pairs)
FastQ single records discarded: 0 (from PE1: 0, from PE2: 0)


FastQ records kept: 10298
FastQ records discarded: 632350

[1469553759] Preparing assembly of unmapped reads from filtered fastq files using /usr/local/apps/popins/05b1dd1/velvet-1.2.10/velveth
[0.000000] Reading FastQ file tmp_yeNQXV/filtered.single.fastq;
[0.068507] 10298 sequences found
[0.068509] Done
[0.070367] Reading FastQ file tmp_yeNQXV/filtered.paired.1.fastq;
[0.072210] Reading FastQ file tmp_yeNQXV/filtered.paired.2.fastq;
[0.072243] 0 sequences found in total in the paired sequence files
[0.072244] Done
[0.082337] Reading read set file tmp_yeNQXV/assembly/Sequences;
[0.086323] 10298 sequences found
[0.104871] Done
[0.104874] 10298 sequences in total.
[0.106545] Writing into roadmap file tmp_yeNQXV/assembly/Roadmaps...
[0.112231] Inputting sequences...
[0.112236] Inputting sequence 0 / 10298
[81.994406]  === Sequences loaded in 81.882184 s
[81.998105] Done inputting sequences
[81.998110] Destroying splay table
[82.000464] Splay table destroyed
[1469553841] Assembling unmapped reads from filtered fastq files using /usr/local/apps/popins/05b1dd1/velvet-1.2.10/velvetg
[0.000000] Reading roadmap file tmp_yeNQXV/assembly/Roadmaps
[0.020491] 10298 roadmaps read
[0.020548] Creating insertion markers
[0.020793] Ordering insertion markers
[0.021121] Counting preNodes
[0.021898] 29 preNodes counted, creating them now
[0.053431] Adjusting marker info...
[0.053438] Connecting preNodes
[0.053728] Cleaning up memory
[0.053765] Done creating preGraph
[0.053767] Concatenation...
[0.053811] Renumbering preNodes
[0.053819] Initial preNode count 29
[0.053832] Destroyed 8 preNodes
[0.053836] Concatenation over!
[0.053837] Clipping short tips off preGraph
[0.053843] Concatenation...
[0.053847] Renumbering preNodes
[0.053848] Initial preNode count 21
[0.053849] Destroyed 15 preNodes
[0.053849] Concatenation over!
[0.053850] 13 tips cut off
[0.053851] 6 nodes left
[0.057155] Writing into pregraph file tmp_yeNQXV/assembly/PreGraph...
[0.068400] Reading read set file tmp_yeNQXV/assembly/Sequences;
[0.077900] 10298 sequences found
[0.103926] Done
[0.120062] Reading pre-graph file tmp_yeNQXV/assembly/PreGraph
[0.120123] Graph has 6 nodes and 10298 sequences
[0.123189] Scanning pre-graph file tmp_yeNQXV/assembly/PreGraph for k-mers
[0.123230] 58 kmers found
[0.127915] Sorting kmer occurence table ... 
[0.135055] Sorting done.
[0.135057] Computing acceleration table... 
[26.218911] Computing offsets... 
[26.218942] Ghost Threading through reads 0 / 10298
[26.284895]  === Ghost-Threaded in 0.065953 s
[26.284903] Threading through reads 0 / 10298
[26.344608]  === Threaded in 0.059704 s
[26.350593] Correcting graph with cutoff 0.200000
[26.350655] Determining eligible starting points
[26.350664] Done listing starting nodes
[26.350664] Initializing todo lists
[26.350665] Done with initilization
[26.350666] Activating arc lookup table
[26.350667] Done activating arc lookup table
[26.350673] Concatenation...
[26.350676] Renumbering nodes
[26.350676] Initial node count 6
[26.350678] Removed 0 null nodes
[26.350681] Concatenation over!
[26.350683] Clipping short tips off graph, drastic
[26.350684] Concatenation...
[26.350685] Renumbering nodes
[26.350685] Initial node count 6
[26.350686] Removed 0 null nodes
[26.350687] Concatenation over!
[26.350687] 6 nodes left
[26.351749] Writing into graph file tmp_yeNQXV/assembly/Graph2...
[26.356030] Measuring median coverage depth...
[26.356038] Median coverage depth = 1.444444
[26.357609] Removing contigs with coverage < 2.000000...
[26.357624] Concatenation...
[26.357626] Renumbering nodes
[26.357627] Initial node count 6
[26.357629] Removed 2 null nodes
[26.357631] Concatenation over!
[26.357632] Concatenation...
[26.357633] Renumbering nodes
[26.357633] Initial node count 4
[26.357634] Removed 0 null nodes
[26.357635] Concatenation over!
[26.357639] Applying an upper coverage cutoff of 100.000000...
[26.357643] Concatenation...
[26.357644] Renumbering nodes
[26.357644] Initial node count 4
[26.357645] Removed 0 null nodes
[26.357646] Concatenation over!
[26.357647] Clipping short tips off graph, drastic
[26.357647] Concatenation...
[26.357648] Renumbering nodes
[26.357648] Initial node count 4
[26.357649] Removed 0 null nodes
[26.357649] Concatenation over!
[26.357650] 4 nodes left
[26.357652] Read coherency...
[26.357653] Identifying unique nodes
[26.357654] Done, 0 unique nodes counted
[26.357655] Trimming read tips
[26.357655] Renumbering nodes
[26.357656] Initial node count 4
[26.357657] Removed 0 null nodes
[26.357657] Confronted to 0 multiple hits and 0 null over 0
[26.357658] Read coherency over!
[26.357840] Starting pebble resolution...
[26.357962] Computing read to node mapping array sizes
[26.358006] Computing read to node mappings
[26.358008] Estimating library insert lengths...
[26.358091] Done
[26.358092] Computing direct node to node mappings
[26.358096] Scaffolding node 0
[26.358097]  === Nodes Scaffolded in 0.000005 s
[26.358103] Preparing to correct graph with cutoff 0.200000
[26.358128] Cleaning memory
[26.358131] Deactivating local correction settings
[26.358137] Pebble done.
[26.358138] Concatenation...
[26.358139] Renumbering nodes
[26.358140] Initial node count 4
[26.358145] Removed 0 null nodes
[26.358146] Concatenation over!
[26.358147] Removing reference contigs with coverage < 2.000000...
[26.358150] Concatenation...
[26.358150] Renumbering nodes
[26.358151] Initial node count 4
[26.358152] Removed 0 null nodes
[26.358153] Concatenation over!
[26.361765] Writing contigs into tmp_yeNQXV/assembly/contigs.fa...
[26.363925] Writing into stats file tmp_yeNQXV/assembly/stats.txt...
[26.367318] Writing into graph file tmp_yeNQXV/assembly/LastGraph...
[26.367814] Estimated Coverage = 1.444444
Final graph has 4 nodes and n50 of 7, max 7, total 25, using 0/10298 reads
[1469553868] Temporary directory tmp_yeNQXV removed.
[1469553868] popins assemble finished in 118 seconds.