search

blahah / transrate

Understand your transcriptome assembly
http://hibberdlab.com/transrate
Other
100 stars 34 forks source link

transrate stuck in "Calculating comparative metrics" step #185

Open IdoBar opened 8 years ago

IdoBar commented 8 years ago

I've used transrate with the following command: transrate --assembly $DAVE_GG_DIR/GG_Gonads_de-novo.Trinity.fasta --reference ../Perciformes_proteins.pep.uniq.fasta --left $DAVE_GG_DIR/symlinks/bbduk_clean_GG_Gonads_R1.fq --right $DAVE_GG_DIR/symlinks/bbduk_clean_GG_Gonads_R2.fq --threads 32 and got the following output

[ INFO] 2016-03-11 15:43:09 : Loading assembly: /home/ibar/data/Dave/AGRF_CAGRF11381_C8TR7ANXX/GG_Gonads_de-novo.Trinity.fasta
[ INFO] 2016-03-11 15:44:21 : Analysing assembly: /home/ibar/data/Dave/AGRF_CAGRF11381_C8TR7ANXX/GG_Gonads_de-novo.Trinity.fasta
[ INFO] 2016-03-11 15:44:21 : Results will be saved in /home/ibar/data/Dave/AGRF_CAGRF11381_C8TR7ANXX/QC/Assembly_stats/transrate_results/transrate_results/GG_Gonads_de-novo.Trinity
[ INFO] 2016-03-11 15:44:21 : Calculating contig metrics...
[ INFO] 2016-03-11 15:45:50 : Contig metrics:
[ INFO] 2016-03-11 15:45:50 : -----------------------------------
[ INFO] 2016-03-11 15:45:50 : n seqs                       315761
[ INFO] 2016-03-11 15:45:50 : smallest                        201
[ INFO] 2016-03-11 15:45:50 : largest                       25816
[ INFO] 2016-03-11 15:45:50 : n bases                   283299055
[ INFO] 2016-03-11 15:45:50 : mean len                     897.19
[ INFO] 2016-03-11 15:45:50 : n under 200                       0
[ INFO] 2016-03-11 15:45:50 : n over 1k                     70610
[ INFO] 2016-03-11 15:45:50 : n over 10k                      666
[ INFO] 2016-03-11 15:45:50 : n with orf                    58203
[ INFO] 2016-03-11 15:45:50 : mean orf percent              49.15
[ INFO] 2016-03-11 15:45:50 : n90                             306
[ INFO] 2016-03-11 15:45:50 : n70                             834
[ INFO] 2016-03-11 15:45:50 : n50                            1968
[ INFO] 2016-03-11 15:45:50 : n30                            3454
[ INFO] 2016-03-11 15:45:50 : n10                            6461
[ INFO] 2016-03-11 15:45:50 : gc                             0.46
[ INFO] 2016-03-11 15:45:50 : gc skew                        0.01
[ INFO] 2016-03-11 15:45:50 : at skew                         0.0
[ INFO] 2016-03-11 15:45:50 : cpg ratio                      1.44
[ INFO] 2016-03-11 15:45:50 : bases n                           0
[ INFO] 2016-03-11 15:45:50 : proportion n                    0.0
[ INFO] 2016-03-11 15:45:50 : linguistic complexity          0.15
[ INFO] 2016-03-11 15:45:50 : Contig metrics done in 89 seconds
[ INFO] 2016-03-11 15:45:50 : Calculating read diagnostics...
[ INFO] 2016-03-11 18:31:54 : Read mapping metrics:
[ INFO] 2016-03-11 18:31:54 : -----------------------------------
[ INFO] 2016-03-11 18:31:54 : fragments                 272483130
[ INFO] 2016-03-11 18:31:54 : fragments mapped          241721197
[ INFO] 2016-03-11 18:31:54 : p fragments mapped             0.89
[ INFO] 2016-03-11 18:31:54 : good mappings             215099123
[ INFO] 2016-03-11 18:31:54 : p good mapping                 0.79
[ INFO] 2016-03-11 18:31:54 : bad mappings               26622074
[ INFO] 2016-03-11 18:31:54 : potential bridges             85257
[ INFO] 2016-03-11 18:31:54 : bases uncovered            45125952
[ INFO] 2016-03-11 18:31:54 : p bases uncovered              0.16
[ INFO] 2016-03-11 18:31:54 : contigs uncovbase            143151
[ INFO] 2016-03-11 18:31:54 : p contigs uncovbase            0.45
[ INFO] 2016-03-11 18:31:54 : contigs uncovered             38977
[ INFO] 2016-03-11 18:31:54 : p contigs uncovered            0.12
[ INFO] 2016-03-11 18:31:54 : contigs lowcovered           241971
[ INFO] 2016-03-11 18:31:54 : p contigs lowcovered           0.77
[ INFO] 2016-03-11 18:31:54 : contigs segmented             22679
[ INFO] 2016-03-11 18:31:54 : p contigs segmented            0.07
[ INFO] 2016-03-11 18:31:54 : Read metrics done in 9964 seconds
[ INFO] 2016-03-11 18:31:54 : Calculating comparative metrics...

That was 4 days ago and it doesn't seem like transrate is producing any output since, though it is still working in 100% cpu usage and almost 15g of memory:

VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 11.550g 3.392g   1208 R  99.5  0.7   5023:42 ruby

Any idea what is happening and whether I should keep waiting for any additional output?

Thanks, Ido

blahah commented 8 years ago

Hi Ido,

Sorry for the trouble you're having and thanks for reporting it.

Can you look inside the transrate output directory and tell me what you see there? I'd like to see whether transrate has run the BLAST steps - it may be that the BLAST outputs are huge (you have a lot of contigs) and it is taking a long time to parse.

IdoBar commented 8 years ago

Hi,

By the look of the output directory content, it seems like the 2 BLAST steps were competed successfully (and are not that big), so I don't think that is the case:

-rw-r--r-- 1 ibar domain users 3.9M Mar 11 18:31 assembly_score_optimisation.csv
-rw-r--r-- 1 ibar domain users  36M Mar 11 18:31 bad.GG_Gonads_de-novo.Trinity.fasta
-rw-r--r-- 1 ibar domain users  44G Mar 11 17:39 bbduk_clean_GG_Gonads_R1.fq.bbduk_clean_GG_Gonads_R2.fq.GG_Gonads_de-novo.Trinity.assigned.bam
-rwxr----- 1 ibar domain users  59G Mar 11 16:33 bbduk_clean_GG_Gonads_R1.fq.bbduk_clean_GG_Gonads_R2.fq.GG_Gonads_de-novo.Trinity.bam*
-rw-r--r-- 1 ibar domain users   10 Mar 11 16:33 bbduk_clean_GG_Gonads_R1.fq-bbduk_clean_GG_Gonads_R2.fq-read_count.txt
drwxr-xr-x 2 ibar domain users 4.0K Mar 11 15:47 GG_Gonads_de-novo.Trinity/
-rw-r--r-- 1 ibar domain users  19M Mar 11 18:29 GG_Gonads_de-novo.Trinity.fasta_bam_info.csv
-rw-r--r-- 1 ibar domain users  14M Mar 11 16:57 GG_Gonads_de-novo.Trinity.fasta_quant.sf
-rw-r--r-- 1 ibar domain users 228M Mar 11 20:18 GG_Gonads_de-novo.Trinity_into_Perciformes_proteins.pep.uniq.1.blast
-rw-r--r-- 1 ibar domain users  76M Mar 11 18:32 GG_Gonads_de-novo.Trinity.nhr
-rw-r--r-- 1 ibar domain users 3.7M Mar 11 18:32 GG_Gonads_de-novo.Trinity.nin
-rw-r--r-- 1 ibar domain users  68M Mar 11 18:32 GG_Gonads_de-novo.Trinity.nsq
-rw-r--r-- 1 ibar domain users 243M Mar 11 18:31 good.GG_Gonads_de-novo.Trinity.fasta
drwxr-xr-x 2 ibar domain users 4.0K Mar 11 16:57 libParams/
drwxr-xr-x 2 ibar domain users 4.0K Mar 11 16:33 logs/
-rw-r--r-- 1 ibar domain users 105M Mar 11 21:03 Perciformes_proteins.pep.uniq_into_GG_Gonads_de-novo.Trinity.2.blast
-rw-r--r-- 1 ibar domain users 2.7M Mar 11 18:32 Perciformes_proteins.pep.uniq.phr
-rw-r--r-- 1 ibar domain users 229K Mar 11 18:32 Perciformes_proteins.pep.uniq.pin
-rw-r--r-- 1 ibar domain users  14M Mar 11 18:32 Perciformes_proteins.pep.uniq.psq
-rw-r--r-- 1 ibar domain users 3.8K Mar 15 08:42 transrate.log

I'm using Python 2.7.11 and Ruby 2.3.0 if that helps.

Thanks, Ido

blahah commented 8 years ago

Hmm that's pretty strange. Those are quite large blast results, but it shouldn't take so long to process them.

Your read metrics are already done - you could just kill the process. If you re-run it, it will find all the existing outputs and work with them so should rapidly get back to where it left off. If the problem was a one-off, it might then complete normally.

Can you let me know if this works?

IdoBar commented 8 years ago

I'm trying that, meanwhile, this is the output that came out when I killed the process (Ctrl+C):

^C/home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:400:in `block (3 levels) in find_reciprocals': Interrupt
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:399:in `each'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:399:in `each_with_index'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:399:in `block (2 levels) in find_reciprocals'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:396:in `each'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:396:in `each_with_index'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:396:in `block in find_reciprocals'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:395:in `each_pair'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:395:in `find_reciprocals'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/ruby/2.2.0/gems/crb-blast-0.6.4/lib/crb-blast/crb-blast.rb:515:in `run'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/comparative_metrics.rb:154:in `run_crb_blast'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/comparative_metrics.rb:23:in `run'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/transrater.rb:104:in `comparative_metrics'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/cmdline.rb:481:in `comparative_metrics'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/cmdline.rb:381:in `block in analyse_assembly'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/cmdline.rb:376:in `chdir'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/cmdline.rb:376:in `analyse_assembly'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/cmdline.rb:38:in `block (2 levels) in run'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/cmdline.rb:37:in `zip'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/cmdline.rb:37:in `block in run'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/cmdline.rb:32:in `chdir'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/lib/transrate/cmdline.rb:32:in `run'
        from /home/ibar/etc/tools/Trinity/transrate-1.0.1-linux-x86_64/lib/app/bin/transrate:23:in `<main>'

You'd might be able to find a clue there?

IdoBar commented 8 years ago

I've re-run the analysis using the same command and it stalled again in the same step (for the last 36 hours). Any ideas?

Cheers, Ido

blahah commented 8 years ago

@cboursnell looks like a crb-blast issue - any ideas?

meganrh19 commented 8 years ago

Just fyi, I'm having the same issue - with the same output.

blahah commented 8 years ago

Pinging @cboursnell again

blahah commented 8 years ago

monthly ping for @cboursnell !