pick_closed_reference_otus.py sleeping after 12h, no results

[André Soares]

Hello there,

having started pick_closed_reference_otus.py on a large dataset - 14.8GB fna - the process is now sleeping after some 12h of working.

The command was:

pick_closed_reference_otus.py \
  -i demulti_seqs_chimerafree.fna \
  -r $reference_seqs \
  -t $reference_tax \
  -p $uclust_params \
  -a \
  -O 6 \
  -o ./cr_otus

refs were according to SILVA 123,
uclust params is: pick_otus:otu_picking_method uclust_ref

Outputs so far are:
POTU_ggMo_                 POTU_ggMo_.2_clusters.uc   POTU_ggMo_.3_otus.log      POTU_ggMo_.5_clusters.uc
POTU_ggMo_.0_clusters.uc   POTU_ggMo_.2_failures.txt  POTU_ggMo_.3_otus.txt      POTU_ggMo_.5_failures.txt
POTU_ggMo_.0_failures.txt  POTU_ggMo_.2_otus.log      POTU_ggMo_.4_clusters.uc   POTU_ggMo_.5_otus.log
POTU_ggMo_.0_otus.log      POTU_ggMo_.2_otus.txt      POTU_ggMo_.4_failures.txt  POTU_ggMo_.5_otus.txt
POTU_ggMo_.0_otus.txt      POTU_ggMo_.3_clusters.uc   POTU_ggMo_.4_otus.log
POTU_ggMo_.1_clusters.uc   POTU_ggMo_.3_failures.txt  POTU_ggMo_.4_otus.txt

Right now I can see the following processes:
poller.py - Sleeping - 79.7MB RAM, 0% CPU
parallel_pick_otus_uclust_ref.py - Sleeping - 10.4MB RAM, 0% CPU

The last files were created 4h ago....

• What should I do here? Wait?

Here's my print_qiime_config -f:
print_qiime_config.py -f

System information
==================
         Platform:    linux2
   Python version:    2.7.6 (default, Jun 22 2015, 17:58:13)  [GCC 4.8.2]
Python executable:    /usr/bin/python

QIIME default reference information
===================================
For details on what files are used as QIIME's default references, see here:
 https://github.com/biocore/qiime-default-reference/releases/tag/0.1.3

Dependency versions
===================
                QIIME library version:    1.9.1
                 QIIME script version:    1.9.1
      qiime-default-reference version:    0.1.3
                        NumPy version:    1.11.0
                        SciPy version:    0.17.1
                       pandas version:    0.18.1
                   matplotlib version:    1.4.3
                  biom-format version:    2.1.5
                         h5py version:    2.5.0 (HDF5 version: 1.8.11)
                         qcli version:    0.1.1
                         pyqi version:    0.3.2
                   scikit-bio version:    0.2.3
                       PyNAST version:    1.2.2
                      Emperor version:    0.9.51
                      burrito version:    0.9.1
             burrito-fillings version:    0.1.1
                    sortmerna version:    SortMeRNA version 2.0, 29/11/2014
                    sumaclust version:    SUMACLUST Version 1.0.00
                        swarm version:    Swarm 1.2.19 [May 13 2016 21:04:23]
                                gdata:    Installed.
RDP Classifier version (if installed):    Not installed.
          Java version (if installed):    1.8.0_91

QIIME config values
===================
For definitions of these settings and to learn how to configure QIIME, see here:
 http://qiime.org/install/qiime_config.html
 http://qiime.org/tutorials/parallel_qiime.html

                     blastmat_dir:    None
      pick_otus_reference_seqs_fp:    /usr/local/lib/python2.7/dist-packages/qiime_default_reference/gg_13_8_otus/rep_set/97_otus.fasta
                         sc_queue:    all.q
      topiaryexplorer_project_dir:    None
     pynast_template_alignment_fp:    /usr/local/lib/python2.7/dist-packages/qiime_default_reference/gg_13_8_otus/rep_set_aligned/85_otus.pynast.fasta
                  cluster_jobs_fp:    start_parallel_jobs.py
pynast_template_alignment_blastdb:    None
assign_taxonomy_reference_seqs_fp:    /usr/local/lib/python2.7/dist-packages/qiime_default_reference/gg_13_8_otus/rep_set/97_otus.fasta
                     torque_queue:    friendlyq
                    jobs_to_start:    1
                       slurm_time:    None
            denoiser_min_per_core:    50
assign_taxonomy_id_to_taxonomy_fp:    /usr/local/lib/python2.7/dist-packages/qiime_default_reference/gg_13_8_otus/taxonomy/97_otu_taxonomy.txt
                         temp_dir:    /tmp/
                     slurm_memory:    None
                      slurm_queue:    None
                      blastall_fp:    blastall
                 seconds_to_sleep:    1

[Colin Brislawn]

Hello Andre,

14.8GB is a large dataset indeed! Someone large data sets can 'overflow' the memory of the worker machine, causing the script to slow down to a crawl. Thanks for posting your script and full log file. Can you tell me more about your computer, like how many CPUs and how much RAM it has? This will help me estimate if the file size is slowing down the script or if something else could be going wrong. 

Thank you,

Colin

[André Soares]

Hello again Colin!

What worries me is that both those processes are now 'Sleeping', so nothing is happening...
I have an Intel® Core™ i7-4790 CPU @ 3.60GHz × 8  and 32 GB RAM!

Cheers and many thanks,
André

[Colin Brislawn]

Hello Andre,

Well, that should be enough RAM to work through that data set, especially with closed-ref OTU picking! Just to be sure, could you use the linux command 'top' to check in on 'Mem: xxxK used, xxxk, free' and 'Swap: xxx used, xxx free'?  

I wonder if something else is going wrong for some small reason... Are you running qiime natively in linux or inside of a virtual box? Are you using an special uclust parameters which could increase RAM?

I'm looking for clues to what could be going wrong, and any thoughts you have would be very helpful. 

Thanks!  

Colin 

[André Soares]

Hey Colin,

Here's the data from top:
KiB Mem:  32817140 total,  5614200 used, 27202940 free,    15660 buffers
KiB Swap:  8256508 total,  1102712 used,  7153796 free.  1373860 cached Mem

Running Ubuntu natively, and QIIME 1.9.1 as you saw before...
For uclust all I got into the parameters file was: pick_otus:otu_picking_method uclust_ref

I got my SILVA refs from here: https://www.dropbox.com/s/ndkfgyy2n4yd0b4/SILVA123_QIIME_release.zip?dl=0
Do you think that might be it?

Aside from that I've no idea what's wrong... I find it very weird that the process went sleeping without any warnings and not done anything for 15h now. Has that happenned to you before?

Cheers,

André

[Colin Brislawn]

Hello Andre,

Thanks for the speedy reply. 

Top looks pretty good, and we have confirmed that you have plenty of RAM to spare... When I've got these errors, it's because I ran out of RAM, but that's not what's happening here. 

Maybe this has something to do with Silva. Hopefully a qiime dev can comment more.

Colin 

[André Soares]

Hey again,

Are you aware of any 'trustworthy' QIIME-adapted SILVA 123 refs available meanwhile ?

Thanks for the connection @Colin!
Cheers,
André

[TonyWalters]

That reference dataset has worked on multiple datasets.  Try a subset of your data, e.g. 10000 reads and see if it completes. You can also look through all of the .uc files (use tail to see the end of the files) and look for errors there.

[André Soares]

Hello again,

As suggested by Tony I tried the same thing on a 1000 seqs-long .fna.

The process was shortly killed and  got the following on the log file:

Traceback (most recent call last):
  File "/usr/local/bin/pick_closed_reference_otus.py", line 233, in <module>
    main()
  File "/usr/local/bin/pick_closed_reference_otus.py", line 224, in main
    status_update_callback=status_update_callback)
  File "/usr/local/lib/python2.7/dist-packages/qiime/workflow/upstream.py", line 506, in run_pick_closed_reference_otus
    close_logger_on_success=close_logger_on_success)
  File "/usr/local/lib/python2.7/dist-packages/qiime/workflow/util.py", line 122, in call_commands_serially
    raise WorkflowError(msg)
qiime.workflow.util.WorkflowError:

*** ERROR RAISED DURING STEP: Make OTU table
Command run was:
 make_otu_table.py -i ./subset_cr_otus/uclust_ref_picked_otus/subset_demulti_seqs_chimerafree_otus.txt -t /media/andre/B2F8C9A0F8C962E9/MetaAn_DS/SILVA_123/consensus_taxonomy_all_levels.txt -o ./subset_cr_otus/otu_table.biom
Command returned exit status: 1
Stdout:

Stderr
Traceback (most recent call last):
  File "/usr/local/bin/make_otu_table.py", line 119, in <module>
    main()
  File "/usr/local/bin/make_otu_table.py", line 115, in main
    write_biom_table(biom_otu_table, opts.output_biom_fp)
  File "/usr/local/lib/python2.7/dist-packages/qiime/util.py", line 569, in write_biom_table
    "Attempting to write an empty BIOM table to disk. "
qiime.util.EmptyBIOMTableError: Attempting to write an empty BIOM table to disk. QIIME doesn't support writing empty BIOM output files.

Does this help?

Cheers,
André

[TonyWalters]

Which reference file are you using? it's not exactly clear from these posts. Do you know if you're reads have barcodes or other non-16S/18S data in them? Can you try clustering against Greengenes and see if this subset also fails?

[André Soares]

Hello again,

*This fail might have been due to no valid OTUs having been found.
Just noticed how the log file shows that. Trying to use a bigger subset to find out how that is going.

Reference files are:
SILVA_123/97_otus_16S.fasta
SILVA_123/consensus_taxonomy_all_levels.txt

This dataset comes from multiple studies concerning only 16S, but involving some 5-6 regions.

Will try Greenges out and see how that works...

[André Soares]

Hello again all,

Re-ran everything and got the same results: stuck on OTU picking, with all clusters, otus and failures created 7h ago but no progress from thereon.

I did, however noticed high rates of failures and that job kMY9_1 isn't finished yet after all those hours:
==> POTU_kMY9_.0_otus.log <==
Num OTUs:1705
Num new OTUs:0
Num failures:5256681
Result path: ./cr_otus_labelled_split_libs_chimerafree/uclust_ref_picked_otus/POTU_kMY9_/POTU_kMY9_.0_otus.txt
==> POTU_kMY9_.2_otus.log <==
Num OTUs:3
Num new OTUs:0
Num failures:5294419
Result path: ./cr_otus_labelled_split_libs_chimerafree/uclust_ref_picked_otus/POTU_kMY9_/POTU_kMY9_.2_otus.txt
==> POTU_kMY9_.3_otus.log <==
Num OTUs:1179
Num new OTUs:0
Num failures:5269573
Result path: ./cr_otus_labelled_split_libs_chimerafree/uclust_ref_picked_otus/POTU_kMY9_/POTU_kMY9_.3_otus.txt
==> POTU_kMY9_.4_otus.log <==
Num OTUs:782
Num new OTUs:0
Num failures:5274476
Result path: ./cr_otus_labelled_split_libs_chimerafree/uclust_ref_picked_otus/POTU_kMY9_/POTU_kMY9_.4_otus.txt
==> POTU_kMY9_.5_otus.log <==
Num OTUs:15
Num new OTUs:0
Num failures:5294338
Result path: ./cr_otus_labelled_split_libs_chimerafree/uclust_ref_picked_otus/POTU_kMY9_/POTU_kMY9_.5_otus.txta

Any ideas?

Thanks again,
André

[TonyWalters]

So very few of your reads are clustering. You might try running adjust_seqs_orientation.py on your subset of 1000 reads and see if the reverse complemented reads improve clustering. The other factor that could interfere with clustering is non-16S data in the reads (e.g. barcodes/adapters/linkers). If you blast some of these reads on the NCBI site, are there overhangs at the ends that do not match in the results?