epruesse / SINA

SINA - Reference based multiple sequence alignment
https://sina.readthedocs.io
GNU General Public License v3.0
40 stars 4 forks source link

Sina abruptly ends with "Killed" and no information. #74

Closed TorkelE closed 3 years ago

TorkelE commented 5 years ago

So I have some files with rRNAs which I wish to align (in fasta files, different domains and type of rRNAs, but always the same in each file).

I try to use sina and the following command (on ubuntu 18.04, conda version 6.11.4, sina version 1.6.0, python version 3.7.3):

sina -i Archaea/5SrRNAs.fasta -o Archaea/5SrRNAs_aligned.fasta --db SILVA_132_LSUParc_12_12_17_opt.arb

Things then starts up nicely, but in the middle of building index it just ends with the word "Killed", and no information of why. I have tried several times, here is the results:

13:39:21 [famfinder] Option --ptdb deprecated; please use --db instead
13:39:37 [Search (internal)] No cached index found.
Processing: 0 [00:00:14]████████████████| 907382/907382 [00:00:00 / 00:00:00]
Building Index:  75% |█████████████▋    | 684833/907382 [00:22:30 / 00:07:18]Killed
14:06:01 [Search (internal)] No cached index found.
Processing: 0 [00:00:15]██████████████████████████████████████████| 907382/907382 [00:00:00 / 00:00:00]
Killedng Index:  74% |████████████████████████████████▌           | 670767/907382 [00:21:41 / 00:07:39]

(just copied two attempts out from the terminal)

However, I do not actually get any information on what have gone wrong. I would be happ if someone could help me get the program to work.

epruesse commented 5 years ago

Sorry to hear this. Will try to help. Might be a week or two until I can fully dive into it.

Could be out of memory. Can you checkdmesg and/or append ; echo $?. Also, watch with top from a second terminal.

If that doesn’t help, try running in gdb: gdb --args sina ... then enter run and once it crashes bt.

If you add -v you’ll see each sequence as it’s processed. Could be there is one it doesn’t like.

Elmar

-- message sent from mobile device

On Jul 7, 2019, at 7:45 AM, Torkel notifications@github.com wrote:

So I have some files with rRNAs which I wish to align (in fasta files, different domains and type of rRNAs, but always the same in each file).

I try to use sina and the following command (on ubuntu 18.04, conda version 6.11.4, sina version 1.6.0, python version 3.7.3):

sina -i Archaea/5SrRNAs.fasta -o Archaea/5SrRNAs_aligned.fasta --db SILVA_132_LSUParc_12_12_17_opt.arb Things then starts up nicely, but in the middle of building index it just ends with the word "Killed", and no information of why. I have tried several times, here is the results:

13:39:21 [famfinder] Option --ptdb deprecated; please use --db instead 13:39:37 [Search (internal)] No cached index found. Processing: 0 [00:00:14]████████████████| 907382/907382 [00:00:00 / 00:00:00] Building Index: 75% |█████████████▋ | 684833/907382 [00:22:30 / 00:07:18]Killed 14:06:01 [Search (internal)] No cached index found. Processing: 0 [00:00:15]██████████████████████████████████████████| 907382/907382 [00:00:00 / 00:00:00] Killedng Index: 74% |████████████████████████████████▌ | 670767/907382 [00:21:41 / 00:07:39] (just copied two attempts out from the terminal)

However, I do not actually get any information on what have gone wrong. I would be happ if someone could help me get the program to work.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or mute the thread.

TorkelE commented 4 years ago

Thanks for the quick reply (unlike my, I will blame a travel).

I did run top when I did my last tests, %CPU hitting about 125 and %MEM slowly working up to ~50 before the end. At least this is what I remember, might only have been when I was looking at errors in my old sina 1.2 installation.

Anyway, when I am double checking this now the error is gone, and the alignment seem to be successful. I'm confused, but it is good. I will continue to run alignments on all my files now, but hopefully things continue to turn out well.

TorkelE commented 4 years ago

Just updating again. I have tried aligning several datasets (from Archaea, Bacteria, and Eukaryote). All types of rRNAs as well (5S, 5.8S, 16S, 18S, 23S, and 28S). To run the program I use this line (after activating sina in the terminal).

sina -i [Domain]/[Database Nbr]/[rRNA type].fasta -o [Domain]/[Dataset Nbr]/[rRNA type]_aligned.fasta --db [Database]

[Domain] is either Arcahea, Bacteria, or Eukaryote. [Dataset Nbr] just designates one of my datasets), [rRNA type] is either 5S, 16S, or 23S (for Arachaea and Bacteria) or 5S, 5.8S, 18S, or 28S (for Eukaryote). [Database] is the reference database. I have donwloaded these databases from silva. For 16 and 18S I use "SILVA_132_SSURef_NR99_13_12_17_opt.arb" and for 5S, 5.8S, 23S, and 28S I use "SILVA_132_LSURef_07_12_17_opt.arb".

When I run and watch the "top" infromation %CPU hit something like 750 and %MEM peaks at 65, but is usually around 40. If I run dmesg I get this at the end (runaligh.sh is the master script which runs the alignment for all datasets).

[88005.358426] [30337]  1001 30337     4998       68    73728        0             0 runalign.sh
[88005.358430] [30371]  1001 30371   379284     4373   831488        0             0 Web Content
[88005.358434] [30481]  1001 30481  4806717  3262927 26398720        0             0 sina
[88005.358436] Out of memory: Kill process 30481 (sina) score 720 or sacrifice child
[88005.358450] Killed process 30481 (sina) total-vm:19226868kB, anon-rss:13051708kB, file-rss:0kB, shmem-rss:0kB
[88005.827807] oom_reaper: reaped process 30481 (sina), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB

(That's the last few lines of a rather large output)

If I try using gdb (on the third datasets that fails, some bacterial 23S rRNAs) I get this outpu:

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
15:57:48 [SINA] Aligner ready. Processing sequences
Processing: 0 [00:00:02]█████████████████████████████████████████████████████████████████████| 198843/198843 [00:00:00 / 00:00:00]
[New Thread 0x7ffff4a57700 (LWP 31284)]
[New Thread 0x7ffff3c54700 (LWP 31285)]
[New Thread 0x7ffff3853700 (LWP 31286)]
[New Thread 0x7ffff3051700 (LWP 31289)]
[New Thread 0x7ffff3452700 (LWP 31288)]
[New Thread 0x7ffff2c50700 (LWP 31287)]
Processing:  70% |█████████████████████████████████████████████████████████                        | 482/686 [00:02:31 / 00:01:04]
16:00:20 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
16:00:20 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_LSURef_07_12_17_opt.arb"' ...
[Thread 0x7ffff3853700 (LWP 31286) exited]
[Thread 0x7ffff4a57700 (LWP 31284) exited]
[Thread 0x7ffff284f700 (LWP 31290) exited]
[Thread 0x7ffff3051700 (LWP 31289) exited]
[Thread 0x7ffff3452700 (LWP 31288) exited]
[Thread 0x7ffff3c54700 (LWP 31285) exited]
[Thread 0x7ffff2c50700 (LWP 31287) exited]
[Inferior 1 (process 31280) exited with code 01]

Next, when I run bt I simply get a response No stack..

When I run the same dataset, but adding the -v option I get a lot of printout, but this is the last bit:

16:08:54 [log] align_filter_slv: 
16:08:54 [log] align_log_slv: shifting bases to fit in 1 bases at pos 83939 to 83939;shifting bases to fit in 1 bases at pos 98552 to 98552;shifting bases to fit in 1 bases at pos 98656 to 98656;shifting bases to fit in 1 bases at pos 99188 to 99188;shifting bases to fit in 2 bases at pos 99468 to 99468;shifting bases to fit in 3 bases at pos 105528 to 105528;shifting bases to fit in 3 bases at pos 113871 to 113871;shifting bases to fit in 1 bases at pos 115049 to 115049;shifting bases to fit in 4 bases at pos 116574 to 116576;shifting bases to fit in 3 bases at pos 118688 to 118688;shifting bases to fit in 3 bases at pos 122481 to 122481;shifting bases to fit in 2 bases at pos 122501 to 122501;shifting bases to fit in 1 bases at pos 127568 to 127568;shifting bases to fit in 1 bases at pos 127576 to 127576;shifting bases to fit in 1 bases at pos 128675 to 128675;shifting bases to fit in 1 bases at pos 128989 to 128989;total inserted bases=87;longest insertion=21;total inserted bases before shifting=1;scoring: raw=-3378.21, weight=-4959.91, query-len=2891, aligned-bases=2891, score=0.681104; 
16:08:54 [log] align_quality_slv: 68
16:08:54 [log] align_startpos_slv: 69268
16:08:54 [log] align_stoppos_slv: 129008
16:08:54 [log] aligned_slv: 2019-07-12 15:08:54
16:08:54 [log] nuc: 2891
16:08:54 [log] turn: turn-check disabled
16:08:54 [log] sequence_number: 490
16:08:54 [log] sequence_identifier: |NZ_JXTV01000014|Genomes/bact/files/GCF_001545275.1_ASM154527v1_genomic.gbff.gz|23S|1|2922
16:08:54 [log] align_bp_score_slv: 119
16:08:54 [log] align_cutoff_head_slv: 0
16:08:54 [log] align_cutoff_tail_slv: 0
16:08:54 [log] align_family_slv: CP014344.698224:858.00 MKAI01000022.368:858.00 MJXK01000006.2787:858.00 MJXK01000007.370:858.00 MJXK01000017.152076:858.00 NAAE01000008.364:858.00 MJXK01000011.42884:858.00 CP010306.400533:858.00 JAKQ01000006.103899:858.00 CP006006.1546603:858.00 NAAG01000001.50601:858.00 CP006006.1242425:858.00 CP014344.394294:858.00 CP014344.39689:858.00 CP010306.41400:858.00 CP006006.880002:858.00 MJXK01000007.294513:858.00 MKHW01000051.160:858.00 MKAI01000018.305898:858.00 AUUI01000015.2761:858.00 MKBN01000015.2763:858.00 CP010306.691819:858.00 JOUH01000014.368:858.00 NAAH01000005.140125:858.00 JAKL01000006.368:858.00 MKAI01000019.2763:858.00 LBEC01000027.369:858.00 MKBK01000048.191536:858.00 LLWL01000010.392:858.00 MKBN01000014.2763:858.00 MKAU01000042.369:858.00 MKAU01000042.301463:858.00 MKBD01000009.103424:858.00 MKBD01000031.51203:858.00 MKBN01000013.2763:858.00 MKBN01000012.368:858.00 MKAU01000041.2761:858.00 LBEN01000019.23:858.00 MKAI01000021.368:858.00 MKBD01000027.2762:858.00 
16:08:54 [log] align_filter_slv: 
16:08:54 [log] align_log_slv: copied alignment from (longer) template sequence CP014344:698224; 
16:08:54 [log] align_quality_slv: 100
16:08:54 [log] align_startpos_slv: 66151
16:08:54 [log] align_stoppos_slv: 129018
16:08:54 [log] aligned_slv: 2019-07-12 15:08:54
16:08:54 [log] nuc: 2921
16:08:54 [log] turn: turn-check disabled
16:08:56 [FASTA I/O] read 490 sequences from 981 lines
16:08:56 [FASTA I/O] wrote 483 sequences (0 excluded, 0 relatives)
Processing:  70% |████████████████████████████████████████████████████████▉                        | 483/688 [00:02:48 / 00:01:11]
16:08:56 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
16:08:56 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_LSURef_07_12_17_opt.arb"' ...
16:08:57 [Search (internal)] Timings for Kmer Search: 17.420s (408 calls, load query: 0.000s, count kmers: 0.000s, store: 16.907s)

Finally I show the output after the fails from the various files that failed. In each case, if I rerun the program they all fail at a similar place place (I show the output of a second run, hence the dual texts for each dataset).

A set of bacterial 23S rRNAs.

15:14:58 [SINA] Aligner ready. Processing sequences
Processing:  69% |██████████████████████████████████████████████████████████████████████████████████████████████████████████▎                                                | 264/385 [00:00:53 / 00:00:24]
15:15:53 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
15:15:53 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_LSURef_07_12_17_opt.arb"' ...
15:49:31 [SINA] Aligner ready. Processing sequences
Processing:  69% |███████████████████████████████████▋                | 264/385 [00:00:59 / 00:00:27]
15:50:29 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
15:50:29 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_LSURef_07_12_17_opt.arb"' ...

A set of bacterial 16S rRNAs.

15:16:08 [SINA] Aligner ready. Processing sequences
Processing:  81% |██████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████▎                            | 436/535 [00:00:46 / 00:00:10]
15:16:41 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
15:16:41 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_SSURef_NR99_13_12_17_opt.arb"' ...
15:50:43 [SINA] Aligner ready. Processing sequences
Processing:  82% |██████████████████████████████████████████▍         | 438/537 [00:00:52 / 00:00:11]
15:51:23 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
15:51:23 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_SSURef_NR99_13_12_17_opt.arb"' ...

A set of bacterial 23S rRNAs.

15:16:45 [SINA] Aligner ready. Processing sequences
Processing:  70% |█████████████████████████████████████████████████████████████████████████████████████████████████████████████▏                                             | 486/690 [00:01:50 / 00:00:46]
15:18:38 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
15:18:38 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_LSURef_07_12_17_opt.arb"' ...
15:51:29 [SINA] Aligner ready. Processing sequences
Processing:  70% |████████████████████████████████████▋               | 487/691 [00:02:11 / 00:00:55]
15:53:41 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
15:53:41 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_LSURef_07_12_17_opt.arb"' ...

A set of eukaryote 28S rRNAs.

15:18:43 [SINA] Aligner ready. Processing sequences
Processing:   6% |█████████▏                                                                                                                                                  | 13/220 [00:00:08 / 00:02:22]
./runalign.sh: line 84: 29456 Killed                 
15:53:47 [SINA] Aligner ready. Processing sequences
Processing:   6% |███▏                                                 | 13/220 [00:00:10 / 00:02:42]
./runalign.sh: line 84: 31124 Killed 

A set of eukaryote 5.8S rRNAs.

15:18:55 [SINA] Aligner ready. Processing sequences
Processing: 0 [00:00:04]███████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 198843/198843 [00:00:00 / 00:00:00]
15:18:55 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
15:18:55 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_LSURef_07_12_17_opt.arb"' ...
[*** LOG ERROR ***] [2019-07-12 15:18:56] [Search (internal)] Tried to add incompatible timers
15:54:01 [SINA] Aligner ready. Processing sequences
Processing: 0 [00:00:04]████████████████████████████████████████| 198843/198843 [00:00:00 / 00:00:00]
15:54:01 [SINA] Error during program execution: std::bad_alloc std::bad_alloc
15:54:01 [ARB I/O] Closing ARB database '"sina-1.2.11/NewReferences/SILVA_132_LSURef_07_12_17_opt.arb"' ...
[*** LOG ERROR ***] [2019-07-12 15:54:01] [Search (internal)] Tried to add incompatible timers

(Progress bars probably of uneven size due to different sizes of the terminal winodw when I copied them out)

I hope this can be of some help, if you want I could provide files as well.

epruesse commented 4 years ago

Hi @TorkelE,

sorry for the very late response. The dmesg output is clear - you ran out of memory and the kernel decided that SINA needed to be killed to keep your computer running. Similarly, when you do see the std::bad_alloc, that's almost always also an out-of-memory condition, only that SINA still got to report it.

For the large SILVA SSU reference databases, SINA just needs a lot of memory to fit the database. If I ever find the time, I might write something to use an on-disk database, but that'll be slower.

TorkelE commented 4 years ago

Thank you very much.

epruesse commented 4 years ago

How much memory do you have? You might be able to either use the LTP dataset, or you could try downsampling the reference (something like sina -i bigdatabase.arb --prealigned -o downsampled.arb --select-step 2 to make a DB with just every 2nd sequence).

TorkelE commented 4 years ago

At that time I only had about 16GB RAM I believe. I've recently upgraded to a new computer with 128GB Ram (but haven't tried with that). Maybe that should be enough?

epruesse commented 4 years ago

That's definitely ample. The 16GB should actually have been enough - my laptop has no more and is working fine for most things.

epruesse commented 3 years ago

Closing this in favor of #87