Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Manticore crash when calling call snippets() with libstemmer_fr and index_exact_words #910

Closed
VeerUP opened this issue Oct 13, 2022 · 7 comments

Comments

@VeerUP
Copy link

VeerUP commented Oct 13, 2022

Describe the bug
Manticore crashes when calling call snippets in RT index if morphology is libstemmer_fr and passed an array of more than one text

To Reproduce
Steps to reproduce the behavior:

  1. Create RT index with morphology = libstemmer_fr
    My example:
index fr_index  
{  
    type                = rt  
    rt_mem_limit        = 512M  
    path                = /var/lib/manticore/data/fr_index  
    stopwords           = fr  
    morphology          = libstemmer_fr  
  
    charset_table       = non_cjk  
    blend_chars         =  , &, U 23, U 27  
    ignore_chars        = U AD  
  
    min_word_len        = 2  
    expand_keywords     = exact  
    index_exact_words   = 1  
    html_strip          = 1  
  
    stored_fields       = title, description  
    rt_field            = title  
    rt_field            = description  
  
    rt_attr_string      = company  
    rt_attr_uint        = title_hash  
    rt_attr_uint        = company_hash  
    rt_attr_float       = latitude  
    rt_attr_float       = longitude  
}  
  1. Run call snippets() where the first element is an array of more than one text and the query is more than one word.
    My example:
    CALL SNIPPETS(('test php text 1','test php text 2', 'test php text 3'), 'fr_index', 'php developer');
  2. Wait for the collapse of the manticore
  3. If the manticore did not fall, repeat the request more than 3 times.

Describe the environment:
Manticore Search from Docker container manticoresearch/manticore:5.0.2

Messages from log files:
The log is either missing or an error is thrown:
realloc(): invalid old size
Crash!!! Handling signal 11
Crash!!! Handling signal 6

Additional context
After a complete reindexing, the problem remains.
If morphology = libstemmer_fr is replaced by morphology = lemmatize_en, then the problem is solved

@tomatolog
Copy link
Contributor

could you provide searchd.log to check the BT from the crash log matched to crash you reported?

@VeerUP
Copy link
Author

VeerUP commented Oct 14, 2022

My searchd.log with --logdebugvv

[Fri Oct 14 12:20:03.947 2022] [30] prereaded 21 indexes in 0.002 sec
[Fri Oct 14 12:20:11.587 2022] [40] DEBUG: got events=1, tick=1, interrupted=0
[Fri Oct 14 12:20:11.587 2022] [40] DEBUG: -~-~-~-~-~-~-~-~ MT sched created -~-~-~-~-~-~-~-~
[Fri Oct 14 12:20:11.587 2022] [40] DEBUG: 0x260e510 accepted mysql, sock=162, tick=1
[Fri Oct 14 12:20:11.587 2022] [40] DEBUG: 0x260e510 accepted 1 connections all, tick=1
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: Sending handshake...
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: AsyncSend 98 bytes
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: DiscardProcessed(0) iPos=0->0, iLen=0->0
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: Receiving command... 0 bytes in buf
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: SockRecv 162, for 4096 bytes
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: =========== AsyncRecvNBChunk -1 when read 4096 bytes
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: AsyncRecvNBChunk -1 bytes (4 requested)
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: Still need to receive 4 bytes...
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: Coro::YieldWith (m_iEvent=17), timeout 899999991
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: AddAction action as 162, events 17, timeout -614558546
[Fri Oct 14 12:20:11.587 2022] [34] DEBUG: Kick
[Fri Oct 14 12:20:11.587 2022] [40] DEBUG: got events=1, tick=2, interrupted=0
[Fri Oct 14 12:20:11.587 2022] [40] DEBUG: 0x7fc76c023e20 epoll 160 setup, ev=0x3221225473, op=1, sock=162
[Fri Oct 14 12:20:11.587 2022] [40] DEBUG: got events=1, tick=3, interrupted=0
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: EngageWaiterAndYield awake (m_iSock=162, events=1)
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: SockRecv 162, for 4096 bytes
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: =========== AsyncRecvNBChunk 64 when read 4096 bytes
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: SyncSockRead: AsyncRecvNBChunk returned 64
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: DiscardProcessed(4) iPos=4->0, iLen=64->60
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: AsyncReadMySQLPacketHeader returned 60 len...
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: AsyncSend 11 bytes
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: DiscardProcessed(60) iPos=60->0, iLen=60->0
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: Receiving command... 0 bytes in buf
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: SockRecv 162, for 4096 bytes
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: =========== AsyncRecvNBChunk 37 when read 4096 bytes
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: AsyncRecvNBChunk 37 bytes (4 requested)
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: DiscardProcessed(4) iPos=4->0, iLen=37->33
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: AsyncReadMySQLPacketHeader returned 33 len...
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: LoopClientMySQL command 3, 'select @@version_comment limit 1'
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: AsyncSend 115 bytes
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: DiscardProcessed(33) iPos=33->0, iLen=33->0
[Fri Oct 14 12:20:11.587 2022] [30] DEBUG: Receiving command... 0 bytes in buf
[Fri Oct 14 12:20:11.588 2022] [30] DEBUG: SockRecv 162, for 4096 bytes
[Fri Oct 14 12:20:11.588 2022] [30] DEBUG: =========== AsyncRecvNBChunk -1 when read 4096 bytes
[Fri Oct 14 12:20:11.588 2022] [30] DEBUG: AsyncRecvNBChunk -1 bytes (4 requested)
[Fri Oct 14 12:20:11.588 2022] [30] DEBUG: Still need to receive 4 bytes...
[Fri Oct 14 12:20:11.588 2022] [30] DEBUG: Coro::YieldWith (m_iEvent=17), timeout 899999985
[Fri Oct 14 12:20:11.588 2022] [30] DEBUG: AddAction action as 162, events 17, timeout -614558006
[Fri Oct 14 12:20:11.588 2022] [30] DEBUG: Kick
[Fri Oct 14 12:20:11.588 2022] [40] DEBUG: got events=1, tick=4, interrupted=0
[Fri Oct 14 12:20:11.588 2022] [40] DEBUG: 0x7fc76c023e20 epoll 160 setup, ev=0x3221225473, op=3, sock=162
[Fri Oct 14 12:20:17.165 2022] [40] DEBUG: got events=1, tick=5, interrupted=0
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: EngageWaiterAndYield awake (m_iSock=162, events=1)
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: SockRecv 162, for 4096 bytes
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: =========== AsyncRecvNBChunk 107 when read 4096 bytes
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: SyncSockRead: AsyncRecvNBChunk returned 107
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: DiscardProcessed(4) iPos=4->0, iLen=107->103
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: AsyncReadMySQLPacketHeader returned 103 len...
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: LoopClientMySQL command 3, 'CALL SNIPPETS(('test php text 1','test php text 2', 'test php text 3'), 'fr_index', 'php developer')'
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: MakeSnippetsCoro invoked for 3 tasks
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: MakeSnippetsCoro Coro started
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: last message repeated 2 times
[Fri Oct 14 12:20:17.166 2022] [32] DEBUG: last message repeated 2 times
[Fri Oct 14 12:20:17.166 2022] [34] DEBUG: last message repeated 2 times
[Fri Oct 14 12:20:17.166 2022] [33] DEBUG: MakeSnippetsCoro Coro loop tick 0[2]
[Fri Oct 14 12:20:17.166 2022] [32] DEBUG: MakeSnippetsCoro Coro loop tick 2[0]
[Fri Oct 14 12:20:17.166 2022] [34] DEBUG: MakeSnippetsCoro Coro loop tick 1[1]
------- FATAL: CRASH DUMP -------
[Fri Oct 14 12:20:16.962 2022] [    1]

--- crashed SphinxQL request dump ---
CALL SNIPPETS(('test php text 1','test php text 2', 'test php text 3'), 'fr_index',
 'php developer')
--- request dump end ---
--- local index:
Manticore 5.0.2 348514c86@220530 dev
Handling signal 11
-------------- backtrace begins here ---------------
Program compiled with Clang 13.0.1
Configured with flags: Configured with these definitions: -DDISTR_BUILD=bionic -DUSE_SYSLOG=1 -DWITH_GALERA=1 -DWITH_RE2=1 -DWITH_RE2_FORCE_STATIC=1 -DWITH_STEMMER=1 -DWITH_STEMMER_FORCE_STATIC=1 -DWITH_ICU=1 -DWITH_ICU_FORCE_STATIC=1 -DWITH_SSL=1 -DWITH_ZLIB=1 -DWITH_ODBC=1 -DDL_ODBC=1 -DODBC_LIB=libodbc.so.2 -DWITH_EXPAT=1 -DDL_EXPAT=1 -DEXPAT_LIB=libexpat.so.1 -DWITH_ICONV=1 -DWITH_MYSQL=1 -DDL_MYSQL=1 -DMYSQL_LIB=libmysqlclient.so.20 -DWITH_POSTGRESQL=1 -DDL_POSTGRESQL=1 -DPOSTGRESQL_LIB=libpq.so.5 -DLOCALDATADIR=/var/lib/manticore/data -DFULL_SHARE_DIR=/usr/share/manticore
Host OS is Linux x86_64
Stack bottom = 0x7fc76c023e10, thread stack size = 0x20000
Trying manual backtrace:
Something wrong with thread stack, manual backtrace may be incorrect (fp=0x7fc780001820)
Wrong stack limit or frame pointer, manual backtrace failed (fp=0x7fc780001820, stack=0x7fc76c020000, stacksize=0x20000)
Trying system backtrace:

@sanikolaev
Copy link
Collaborator

Trying system backtrace:

What's next?

@VeerUP
Copy link
Author

VeerUP commented Oct 14, 2022

Nothing, it's the end of the file.

@sanikolaev
Copy link
Collaborator

sanikolaev commented Oct 14, 2022

MRE

Run the following one-liner up to 5 times until it crashes:

mysql> drop table if exists t; create table t(f text) morphology='libstemmer_fr' index_exact_words='1'; CALL SNIPPETS(('test text 1','test text 2'), 't', 'php developer');
--------------
drop table if exists t
--------------

Query OK, 0 rows affected (0.00 sec)

--------------
create table t(f text) morphology='libstemmer_fr' index_exact_words='1'
--------------

Query OK, 0 rows affected (0.01 sec)

--------------
CALL SNIPPETS(('test text 1','test text 2'), 't', 'php developer')
--------------

ERROR 2013 (HY000): Lost connection to MySQL server during query
No connection. Trying to reconnect...
ERROR 2003 (HY000): Can't connect to MySQL server on '0:9306' (61)
ERROR:
Can't connect to the server

Notes

  • Interesting, that in Linux it just crashes, but in MacOS it more often hangs than crashes.
  • Both morphology='libstemmer_fr' and index_exact_words='1' are required for the crash

@sanikolaev sanikolaev added the bug label Oct 14, 2022
@sanikolaev sanikolaev changed the title Manticore crash when calling call snippets() Manticore crash when calling call snippets() with libstemmer_fr and index_exact_words Oct 14, 2022
@VeerUP
Copy link
Author

VeerUP commented Oct 14, 2022

The log result is below. I note that the same problem with morphology='libstemmer_tr'

[Fri Oct 14 12:37:54.398 2022] [30] DEBUG: =========== AsyncRecvNBChunk 76 when read 4096 bytes
[Fri Oct 14 12:37:54.398 2022] [30] DEBUG: AsyncRecvNBChunk 76 bytes (4 requested)
[Fri Oct 14 12:37:54.398 2022] [30] DEBUG: DiscardProcessed(4) iPos=4->0, iLen=76->72
[Fri Oct 14 12:37:54.398 2022] [30] DEBUG: AsyncReadMySQLPacketHeader returned 72 len...
[Fri Oct 14 12:37:54.398 2022] [30] DEBUG: LoopClientMySQL command 3, 'create table t(f text) morphology='libstemmer_fr' index_exact_words='1''
[Fri Oct 14 12:37:54.398 2022] [30] DEBUG: 'attr_update_reserve' - nothing specified, using default value 131072
[Fri Oct 14 12:37:54.398 2022] [30] DEBUG: 'docstore_block_size' - nothing specified, using default value 16384
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: config saved, indexes 1, clusters 0
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: AsyncSend 11 bytes
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: DiscardProcessed(72) iPos=72->0, iLen=72->0
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: Receiving command... 0 bytes in buf
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: SockRecv 14, for 4096 bytes
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: =========== AsyncRecvNBChunk -1 when read 4096 bytes
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: AsyncRecvNBChunk -1 bytes (4 requested)
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: Still need to receive 4 bytes...
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: Coro::YieldWith (m_iEvent=17), timeout 899999991
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: AddAction action as 14, events 17, timeout 448253432
[Fri Oct 14 12:37:54.399 2022] [30] DEBUG: Kick
[Fri Oct 14 12:37:54.399 2022] [41] DEBUG: got events=1, tick=26, interrupted=0
[Fri Oct 14 12:37:54.399 2022] [41] DEBUG: 0x7f1908023e20 epoll 13 setup, ev=0x3221225473, op=3, sock=14
[Fri Oct 14 12:37:54.399 2022] [41] DEBUG: got events=1, tick=27, interrupted=0
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: EngageWaiterAndYield awake (m_iSock=14, events=1)
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: SockRecv 14, for 4096 bytes
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: =========== AsyncRecvNBChunk 71 when read 4096 bytes
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: SyncSockRead: AsyncRecvNBChunk returned 71
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: DiscardProcessed(4) iPos=4->0, iLen=71->67
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: AsyncReadMySQLPacketHeader returned 67 len...
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: LoopClientMySQL command 3, 'CALL SNIPPETS(('test text 1','test text 2'), 't', 'php developer')'
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: MakeSnippetsCoro invoked for 2 tasks
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: MakeSnippetsCoro Coro started
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: last message repeated 1 times
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: MakeSnippetsCoro Coro loop tick 0[1]
[Fri Oct 14 12:37:54.399 2022] [33] DEBUG: MakeSnippetsCoro Coro loop tick 1[0]
------- FATAL: CRASH DUMP -------
[Fri Oct 14 12:37:53.905 2022] [    1]
[Fri Oct 14 12:37:54.399 2022] [26] DEBUG: MakeSnippetsCoro Coro loop tick 0 finished

--- crashed SphinxQL request dump ---
CALL SNIPPETS(('test text 1','test text 2'), 't', 'php developer')
--- request dump end ---
--- local index:
Manticore 5.0.2 348514c86@220530 dev
Handling signal 11
-------------- backtrace begins here ---------------
Program compiled with Clang 13.0.1
Configured with flags: Configured with these definitions: -DDISTR_BUILD=bionic -DUSE_SYSLOG=1 -DWITH_GALERA=1 -DWITH_RE2=1 -DWITH_RE2_FORCE_STATIC=1 -DWITH_STEMMER=1 -DWITH_STEMMER_FORCE_STATIC=1 -DWITH_ICU=1 -DWITH_ICU_FORCE_STATIC=1 -DWITH_SSL=1 -DWITH_ZLIB=1 -DWITH_ODBC=1 -DDL_ODBC=1 -DODBC_LIB=libodbc.so.2 -DWITH_EXPAT=1 -DDL_EXPAT=1 -DEXPAT_LIB=libexpat.so.1 -DWITH_ICONV=1 -DWITH_MYSQL=1 -DDL_MYSQL=1 -DMYSQL_LIB=libmysqlclient.so.20 -DWITH_POSTGRESQL=1 -DDL_POSTGRESQL=1 -DPOSTGRESQL_LIB=libpq.so.5 -DLOCALDATADIR=/var/lib/manticore/data -DFULL_SHARE_DIR=/usr/share/manticore
Host OS is Linux x86_64
Stack bottom = 0x7f19500261c0, thread stack size = 0x20000
Trying manual backtrace:
Something wrong with thread stack, manual backtrace may be incorrect (fp=0x7f1950000dd0)
Stack looks OK, attempting backtrace.
0x2728285354455050
Trying system backtrace:
begin of system symbols:
searchd[0x5984d1]
searchd[0x47ac4f]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7f1966b82890]
/lib/x86_64-linux-gnu/libc.so.6(+0x16e940)[0x7f19668ed940]
searchd[0xc9b145]
searchd[0xc9b01e]
searchd[0xc98f83]
searchd[0x95624e]
searchd[0x956356]
searchd[0x9554e9]
searchd[0x576bba]
searchd[0x5784bb]
searchd[0x4d4bdd]
searchd[0x4d4e21]
searchd[0x983fbf]
searchd[0xdb1f2c]
searchd[0xdce92f]
Trying boost backtrace:
 0# 0x0000000000598524 in searchd
 1# 0x000000000047AC4F in searchd
 2# 0x00007F1966B82890 in /lib/x86_64-linux-gnu/libpthread.so.0
 3# 0x00007F19668ED940 in /lib/x86_64-linux-gnu/libc.so.6
 4# 0x0000000000C9B145 in searchd
 5# 0x0000000000C9B01E in searchd
 6# 0x0000000000C98F83 in searchd
 7# 0x000000000095624E in searchd
 8# 0x0000000000956356 in searchd
 9# 0x00000000009554E9 in searchd
10# 0x0000000000576BBA in searchd
11# 0x00000000005784BB in searchd
12# 0x00000000004D4BDD in searchd
13# 0x00000000004D4E21 in searchd
14# 0x0000000000983FBF in searchd
15# 0x0000000000DB1F2C in searchd
16# 0x0000000000DCE92F in searchd

-------------- backtrace ends here ---------------
Please, create a bug report in our bug tracker (https://github.com/manticoresoftware/manticore/issues)
and attach there:
a) searchd log, b) searchd binary, c) searchd symbols.
Look into the chapter 'Reporting bugs' in the manual
(https://manual.manticoresearch.com/Reporting_bugs)
Dump with GDB is not available
--- BT to source lines (depth 17): ---
conversion failed (error 'No such file or directory'):
  1. Run the command provided below over the crashed binary (for example, 'searchd'):
  2. Attach the source.txt to the bug report.
addr2line -e searchd 0x5984d1 0x47ac4f 0x66b82890 0x668ed940 0xc9b145 0xc9b01e 0xc98f83 0x95624e 
0x956356 0x9554e9 0x576bba 0x5784bb 0x4d4bdd 0x4d4e21 0x983fbf 0xdb1f2c 0xdce92f > source.txt

@sanikolaev
Copy link
Collaborator

Fixed in 2b88781

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants