mariadb client received malformed packet

[daikoz]

Describe the bug with .net SQL client or command line mariadb (like mysql), I receive "received malformed packet" when no result is returned.

To Reproduce Steps to reproduce the behavior:

1. mariadb -h0 -P9306
2. SELECT id FROM Table WHERE MATCH('"fdsfsdfsdfsd"/0.6') LIMIT 30 OPTION max_matches=240, ranker=sph04, max_query_time=120, retry_delay=0;

log Welcome to the MariaDB monitor. Commands end with ; or \g. Your MySQL connection id is 4 Server version: 6.2.12 dc5144d35@230822 git branch manticore-6.2.12...origin/manticore-6.2.12

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MySQL [(none)]> SELECT id FROM Table WHERE MATCH('"fdsfsdfsdfsd"/0.6') LIMIT 30 OPTION max_matches=240, ranker=sph04, max_query_time=120, retry_delay=0; ERROR 2027 (HY000): received malformed packet

Expected behavior Strangely after a lot of retry, I obtain a result: MySQL [(none)]> SELECT id FROM Table WHERE MATCH('"fdsfsdfsdfsd"/0.6') LIMIT 30 OPTION max_matches=240, ranker=sph04, max_query_time=120, retry_delay=0; Empty set (0.000 sec)

Describe the environment: searchd -v Manticore 6.2.12 dc5144d35@230822 Copyright (c) 2001-2016, Andrew Aksyonoff Copyright (c) 2008-2016, Sphinx Technologies Inc (http://sphinxsearch.com) Copyright (c) 2017-2023, Manticore Software LTD (https://manticoresearch.com)

• OS version (uname -a if on a Unix-like system): Linux 5.10.0-22-amd64 SMP Debian 5.10.178-3 (2023-04-22) x86_64 GNU/Linux

Messages from log files: no useful log in log files.

Regression rollback manticore to 6.0.4-230314-1a3a4ea82 is OK:

6.2.12-230822-dc5144d35 => KO 6.2.0-230804-45680f95d => KO 6.0.4-230314-1a3a4ea82 => OK

[sanikolaev]

What's the mariadb client version?

[daikoz]

Follow mariadb version but I reproduce also with .net sql client.

mariadb --version mariadb Ver 15.1 Distrib 10.5.19-MariaDB, for debian-linux-gnu (x86_64) using EditLine wrapper

apt-cache policy mariadb-client mariadb-client: Installed: 1:10.5.19-0+deb11u2

[PavelShilin89]

I do not confirm this bug. Everything works correctly.

1. docker run -it --rm mariadb:10.5.19 bash
2. Installing Manticore in our docker container apt-get update && apt-get install -y wget && wget https://repo.manticoresearch.com/manticore-repo.noarch.deb && dpkg -i manticore-repo.noarch.deb && apt-get update && apt-get install -y manticore manticore-extra && ps ax && mkdir /var/run/manticore && searchd --config /etc/manticoresearch/manticore.conf
3. run mariadb client mariadb -h0 -P9306
4. run SELECT QUERY

Query OK, 0 rows affected (0.009 sec)

Empty set (0.001 sec)

Perhaps you should provide a dump of your table to reproduce the issue.

[bgrainger]

I was also unable to confirm this bug: https://github.com/mysql-net/MySqlConnector/issues/1362#issuecomment-1700378473

[daikoz]

The bug is random. Now, I cannot reproduce with the query provided but on others queries. I try to found a scenario to reproduce each time... Strangely, I can reproduce the bug more easily after migration from 6.0.4 to lastest version without reboot. After reboot server, the bug can be reproduced less frequently.

[daikoz]

I have a scenario.

1. install manticore 6.0.4:

apt-get install manticore=6.0.4-230314-1a3a4ea82 manticore-server=6.0.4-230314-1a3a4ea82 manticore-tools=6.0.4-230314-1a3a4ea82 manticore-dev=6.0.4-230314-1a3a4ea82 manticore-server-core=6.0.4-230314-1a3a4ea82 manticore-common=6.0.4-230314-1a3a4ea82 manticore-buddy=0.4.2-23031500-36757ee

2. get query.log to have a lot of query to replay:

    query_log = /var/log/manticore/query.log
    query_log_format = sphinxql

3. clean query.log:

sed -i 's/\/\*.*\*\/ //g' query.log
sed -i 's/, OPTION.*$/;/g' query.log

4. Launch at least 2 time in 2 console:

while IFS= read -r ligne
do
    mariadb -h0 -P9306 -s -N -e "$ligne" 2>&1 >/dev/null || echo $ligne
done < "query.log"

6. update manticore to lastest version:

apt update && apt full-upgrade && apt autoremove

At the end of update, you will have:

ERROR 2027 (HY000) at line 1: received malformed packet

[PavelShilin89]

Could you provide a dump of manticore search and query.log so that we can test your scenario?

[PavelShilin89]

@daikoz Hello! Is the task relevant?

[daikoz]

Yes, I reproduce always the issue. I try to provide all soon. Where I can upload the dump in private space ?

[tomatolog]

you could upload your data into our private s3 storage as described at our manual https://manual.manticoresearch.com/Reporting_bugs#Uploading-your-data

[daikoz]

data, conf and query are uploaded in issue-1409

[PavelShilin89]

Hello! Thank you for providing the information. I followed your steps, but couldn't find any issues. Everything appears to be in order.

My Steps:

1. Download the archive

scp -r {your user}@dev2.manticoresearch.com:/home/pavel/issue-1409 $(pwd)

2. Run docker with volume

-v $(pwd)/manticore.conf:/etc/manticoresearch/manticore.conf \
-v $(pwd)/data:/var/lib/manticore/data/ \
-v $(pwd)/query.log:/var/log/manticore/query.log \
-it --rm mariadb:10.5.19 bash

4. Run the command

apt-get update && apt-get install -y wget && wget https://repo.manticoresearch.com/manticore-repo.noarch.deb && dpkg -i manticore-repo.noarch.deb && apt-get update && apt-get install manticore=6.0.4-230314-1a3a4ea82 manticore-server=6.0.4-230314-1a3a4ea82 manticore-tools=6.0.4-230314-1a3a4ea82 manticore-dev=6.0.4-230314-1a3a4ea82 manticore-server-core=6.0.4-230314-1a3a4ea82 manticore-common=6.0.4-230314-1a3a4ea82 manticore-buddy=0.4.2-23031500-36757ee && mkdir /var/run/manticore/

5. Run the searchd

searchd

6. Run the command bellow two times:

while IFS= read -r ligne
do
    mariadb -h0 -P9306 -s -N -e "$ligne" 2>&1 >/dev/null || echo $ligne
done < "/var/log/manticore/query.log"

7. Upgrade manticore to latest version:

apt update && apt full-upgrade && apt autoremove 

9. Run the command:

while IFS= read -r ligne
do
    mariadb -h0 -P9306 -s -N -e "$ligne" 2>&1 >/dev/null || echo $ligne
done < "/var/log/manticore/query.log"

[daikoz]

Is it possible de activate manticore's traces to provide you to stack ?

[sanikolaev]

Yes, please do SET GLOBAL LOG_LEVEL=debug, reproduce the issue, save the time it happens and provide the searchd log.

[daikoz]

I launch:

searchd --console --logdebugv

Follow the log when the issue is reproduced:

DEBUG: -~-~-~-~-~-~-~-~ MT sched created -~-~-~-~-~-~-~-~
DEBUG: 0x557fb500d710 accepted mysql, sock=55, tick=97
DEBUG: Sending handshake...
DEBUG: 0x557fb500d710 accepted 1 connections all, tick=97
DEBUG: AsyncSend 78 bytes, sock=55
DEBUG: DiscardProcessed(0) iPos=0->0, iLen=0->0, sock=55
DEBUG: Receiving command... 0 bytes in buf
DEBUG: AsyncRecvNBChunk 215 when read 4096 bytes, sock=55
DEBUG: AsyncRecvNBChunk 215 bytes (4 requested), sock=55
DEBUG: DiscardProcessed(4) iPos=4->0, iLen=215->211, sock=55
DEBUG: AsyncReadMySQLPacketHeader returned 211 len...
DEBUG: HandshakeResponse41. PackedLen=211, hasBytes=179
DEBUG: User: debian-sys-maint
DEBUG: 118 bytes of attrs
DEBUG: _os: Linux
DEBUG: _client_name: libmariadb
DEBUG: _pid: 4391
DEBUG: _client_version: 3.1.22
DEBUG: _platform: x86_64
DEBUG: program_name: mysql
DEBUG: _server_host: 0
DEBUG: AsyncSend 11 bytes, sock=55
DEBUG: DiscardProcessed(211) iPos=211->0, iLen=211->0, sock=55
DEBUG: Receiving command... 0 bytes in buf
DEBUG: AsyncRecvNBChunk -1 when read 4096 bytes, sock=55
DEBUG: AsyncRecvNBChunk -1 bytes (4 requested), sock=55
DEBUG: Still need to receive 4 bytes, sock=55
DEBUG: Coro::YieldWith (m_iEvent=0), timeout 899999995
DEBUG: got events=1, tick=98, interrupted=0
DEBUG: 0x7f883c000c60 epoll 53 setup, ev=0x3221225473, op=EPOLL_CTL_ADD, sock=55
DEBUG: got events=1, tick=99, interrupted=0
DEBUG: EngageWaiterAndYield awake (m_iSock=55, events=1)
DEBUG: AsyncRecvNBChunk 346 when read 4096 bytes, sock=55
DEBUG: SyncSockRead: AsyncRecvNBChunk returned 346, sock=55
DEBUG: DiscardProcessed(4) iPos=4->0, iLen=346->342, sock=55
DEBUG: AsyncReadMySQLPacketHeader returned 342 len...
DEBUG: LoopClientMySQL command 3, 'SELECT id , HIGHLIGHT({ before_match = '[b]', after_match = '[/b]', limit = 200, around = 20 }, Description, QUERY()) FROM Table WHERE MATCH('"opel kadett e 3 5 portes 2 0 butee silent bloc support d ech"/0.6') AND c=250 LIMIT 30 OPTION max_matches=240, comment='comment', ranker=sph04, max_query_time=120, retry_delay=0'
DEBUG: AsyncSend 23 bytes, sock=55
DEBUG: DiscardProcessed(342) iPos=342->0, iLen=342->0, sock=55
DEBUG: Receiving command... 0 bytes in buf
DEBUG: AsyncRecvNBChunk -1 when read 4096 bytes, sock=55
DEBUG: AsyncRecvNBChunk -1 bytes (4 requested), sock=55
DEBUG: Still need to receive 4 bytes, sock=55
DEBUG: Coro::YieldWith (m_iEvent=1), timeout 899999995
DEBUG: got events=1, tick=100, interrupted=0
DEBUG: 0x7f883c000c60 epoll 53 setup, ev=0x3221225473, op=EPOLL_CTL_MOD, sock=55
DEBUG: got events=1, tick=101, interrupted=0
DEBUG: EngageWaiterAndYield awake (m_iSock=55, events=1)
DEBUG: AsyncRecvNBChunk 5 when read 4096 bytes, sock=55
DEBUG: SyncSockRead: AsyncRecvNBChunk returned 5, sock=55
DEBUG: DiscardProcessed(4) iPos=4->0, iLen=5->1, sock=55
DEBUG: AsyncReadMySQLPacketHeader returned 1 len...
DEBUG: LoopClientMySQL command 1
DEBUG: Destroying and closing sock=55
DEBUG: got events=1, tick=102, interrupted=0
DEBUG: 0x7f883c000c60 polling remove, ev=16, sock=55
DEBUG: SockWrapper_c::Impl_c::~Impl_c (); sent 112, received 566
DEBUG: got events=1, tick=103, interrupted=0

The line DEBUG: AsyncSend 23 bytes, sock=55 return only 23 byte.

[PavelShilin89]

@daikoz This may be related to this issue https://github.com/manticoresoftware/manticoresearch/issues/2089. So please check if the problem still persists with the new version of manticore search 6.2.13.

[daikoz]

I don't found the version 6.2.13. However, I see the new version 6.3.0.

[PavelShilin89]

I don't found the version 6.2.13. However, I see the new version 6.3.0.

Yes you are right, the newest version is 6.3.0!

[daikoz]

I think it is the same issue like #2352. When dev with fix will be available, I will test it...

[PavelShilin89]

@daikoz were you able to test the patched version?

[daikoz]

Good news, I cannot reproduce it on dev environnement. But the real final test is the production. For that, I wait the official version 6.3.3.