tomatolog
commented
2 months ago could you upload your backup of the products index that we could try to restore and investigate the hung?
You could upload your data as explained in the manual
Open srgtest opened 2 months ago
tomatolog
commented
2 months ago could you upload your backup of the products index that we could try to restore and investigate the hung?
You could upload your data as explained in the manual
srgtest
commented
2 months ago Uploaded a backup of the product index: issue-116.
srgtest
commented
2 months ago Any information on the problem?
sanikolaev
commented
2 months ago Looks like more tables or additional load are required to reproduce the issue:
snikolaev@dev2:~/issue-116$ manticore-backup --config=manti.conf --backup-dir=backup
Copyright (c) 2023-2024, Manticore Software LTD (https://manticoresearch.com)
Manticore config file: /home/snikolaev/issue-116/manti.conf
Tables to backup: all tables
Backup dir: backup
Manticore config
endpoint = http://127.0.0.1:9316
Manticore versions:
manticore: 6.3.1 00e77610d@24052911 dev
columnar: 2.3.1 4383a90@24052309
secondary: 2.3.1 4383a90@24052309
knn: 2.3.1 4383a90@24052309
buddy: 0.0.0
WARNING: we couldn't fully preserve permissions of the files you've backed up. Be careful when you restore from the backup or re-run the backup as root
2024-06-14 15:50:07 [Info] Starting the backup...
2024-06-14 15:50:07 [Info] Backing up config files...
2024-06-14 15:50:07 [Info] config files - OK
2024-06-14 15:50:07 [Info] Backing up global state files...
2024-06-14 15:50:07 [Info] global state files – OK
2024-06-14 15:50:07 [Info] Backing up tables...
2024-06-14 15:50:07 [Info] products (rt) [2.46G]...
2024-06-14 15:50:18 [Info] OK
2024-06-14 15:50:18 [Info] Running sync
2024-06-14 15:50:35 [Info] OK
2024-06-14 15:50:35 [Info] You can find backup here: /home/snikolaev/issue-116/backup/backup-20240614155007
2024-06-14 15:50:35 [Info] Elapsed time: 27.98s
2024-06-14 15:50:36 [Info] Done
2024-06-14 15:50:36 [Info]
Unfreezing all tables...
2024-06-14 15:50:36 [Info] products...
2024-06-14 15:50:36 [Info] OK
snikolaev@dev2:~/issue-116$ manticore-backup --config=manti.conf --backup-dir=backup --compress
Copyright (c) 2023-2024, Manticore Software LTD (https://manticoresearch.com)
Manticore config file: /home/snikolaev/issue-116/manti.conf
Tables to backup: all tables
Backup dir: backup
Manticore config
endpoint = http://127.0.0.1:9316
Manticore versions:
manticore: 6.3.1 00e77610d@24052911 dev
columnar: 2.3.1 4383a90@24052309
secondary: 2.3.1 4383a90@24052309
knn: 2.3.1 4383a90@24052309
buddy: 0.0.0
WARNING: we couldn't fully preserve permissions of the files you've backed up. Be careful when you restore from the backup or re-run the backup as root
2024-06-14 15:57:28 [Info] Starting the backup...
2024-06-14 15:57:28 [Info] Backing up config files...
2024-06-14 15:57:28 [Info] config files - OK
2024-06-14 15:57:28 [Info] Backing up global state files...
2024-06-14 15:57:28 [Info] global state files – OK
2024-06-14 15:57:28 [Info] Backing up tables...
2024-06-14 15:57:28 [Info] products (rt) [2.46G]...
2024-06-14 15:57:45 [Info] OK
2024-06-14 15:57:45 [Info] Running sync
2024-06-14 15:57:51 [Info] OK
2024-06-14 15:57:51 [Info] You can find backup here: /home/snikolaev/issue-116/backup/backup-20240614155728
2024-06-14 15:57:51 [Info] Elapsed time: 22.55s
2024-06-14 15:57:51 [Info] Done
2024-06-14 15:57:51 [Info]
Unfreezing all tables...
2024-06-14 15:57:51 [Info] products...
2024-06-14 15:57:51 [Info] OKYes, without load there are no problems.
But when you remove a backup to the product index, there are SELECT and UPDATE.
There is an idea that this is due to load and requests. At this moment, the backup is FREEZE before the backup is completed, and requests are still being updated.
And apparently he can no longer apply and defrost everything correctly.
How can I check this?
sanikolaev
commented
2 months ago Pls let me know what update and select queries are running during backup. Simple:
snikolaev@dev2:~$ while true; do mysql -P9315 -h0 -e "update products set nds=21 where id=612731;update products set nds=20 where id=612731"; echo -n .; done;doesn't change anything. Best if you can find something simple which can be run in parallel with manticore-backup which then makes it fail.
srgtest
commented
2 months ago There is a query.log log for this date. In the attachment, there are queries that were executed during the backup period. query.log.2.gz Can be compared by time.
tomatolog
commented
2 months ago from query.log you provided I see the last queries were
/* Wed Jun 05 06:53:18.396 2024 conn 14060 (10.9.2.195:51636) real 0.522 wall 0.523 found 1190452 */ SELECT id,then there is a gap and next queries with errors seems come after daemon restart
...
/* Wed Jun 05 07:13:10.908 2024 conn 19010 (10.180.70.46:57052) */ /* ApplicationName=DBeaver 24.0.5 - Metadata */ SHOW FULL TABLES FROMI can not line up query.log with time of the backup
2024-06-05 07:09:47 [Info] OK
2024-06-05 07:09:47 [Info] products...I suggest to set in your config
searchd
{
query_log_commands = 1that will log the start command then also make an entry then command finished. Then reproduce the case at your side and provide searchd.log query.log along with backup log these we could line up and try to reproduce the case here localy
srgtest
commented
2 months ago When the daemon froze, the requests were no longer received and were not recorded in the logs. I can also attach log files, you can see the time there.
sanikolaev
commented
2 months ago @srgtest what may work out is if you just give us a few typical queries you make and some info about the load like:
srgtest
commented
1 month ago @sanikolaev Ok, I'll try to collect such information and requests.
nxjts
commented
1 month ago I have the same problem. A backup on a loaded database fails with an error and work is blocked.
root@ec2733c78e2d:/tmp# manticore-backup --backup-dir=/tmp
Copyright (c) 2023-2024, Manticore Software LTD (https://manticoresearch.com)
Manticore config file: /etc/manticoresearch/manticore.conf
Tables to backup: all tables
Backup dir: /tmp
Manticore config
endpoint = http://127.0.0.1:9308
Manticore versions:
manticore: 6.3.3 8c855239d@24070613 dev
columnar: 2.3.1 42f2b06@24070110
secondary: 2.3.1 42f2b06@24070110
knn: 2.3.1 42f2b06@24070110
buddy: 0.0.0
2024-07-08 17:46:19 [Info] Starting the backup...
2024-07-08 17:46:19 [Info] Backing up config files...
2024-07-08 17:46:19 [Info] config files - OK
2024-07-08 17:46:19 [Info] Backing up global state files...
2024-07-08 17:46:19 [Info] global state files – OK
2024-07-08 17:46:19 [Info] Backing up tables...
2024-07-08 17:46:19 [Info] tbl01 (rt) [68.024G]...
2024-07-08 17:51:54 [Info] OK
2024-07-08 17:52:54 [Error] Failed to send query to the Manticore Search daemon. Ensure that it is set up to listen for HTTP or HTTPS connections and has the appropriate certificates in place. Additionally, check the 'max_connections' setting in the configuration file to ensure that it has not been exceeded.In searchd.log:
[Mon Jul 8 17:46:19.560 2024] [80] DEBUG: Detached::AddThread called for 'alone_0', tid 80
[Mon Jul 8 17:46:19.561 2024] [80] DEBUG: Detached::RemoveThread called for 80
[Mon Jul 8 17:46:19.561 2024] [80] DEBUG: Terminated thread 80, 'alone_0'
[Mon Jul 8 17:46:19.561 2024] [81] DEBUG: Detached::AddThread called for 'alone_1', tid 81
[Mon Jul 8 17:46:19.562 2024] [81] DEBUG: Detached::RemoveThread called for 81
[Mon Jul 8 17:46:19.562 2024] [81] DEBUG: Terminated thread 81, 'alone_1'
[Mon Jul 8 17:46:19.564 2024] [82] DEBUG: Detached::AddThread called for 'alone_2', tid 82
[Mon Jul 8 17:46:19.565 2024] [82] DEBUG: Detached::RemoveThread called for 82
[Mon Jul 8 17:46:19.565 2024] [82] DEBUG: Terminated thread 82, 'alone_2'
[Mon Jul 8 17:46:19.565 2024] [83] DEBUG: Detached::AddThread called for 'alone_3', tid 83
[Mon Jul 8 17:46:19.565 2024] [83] DEBUG: Detached::RemoveThread called for 83
[Mon Jul 8 17:46:19.565 2024] [83] DEBUG: Terminated thread 83, 'alone_3'
[Mon Jul 8 17:46:19.566 2024] [84] DEBUG: Detached::AddThread called for 'alone_4', tid 84
[Mon Jul 8 17:46:19.566 2024] [84] DEBUG: P01: syntax error, unexpected FREEZE near 'FREEZE tbl01, tbl02'
[Mon Jul 8 17:46:19.566 2024] [84] DEBUG: P03: syntax error, unexpected tablename near 'FREEZE tbl01, tbl02'
[Mon Jul 8 17:46:19.566 2024] [84] WARNING: got ident_all
[Mon Jul 8 17:46:19.667 2024] [15] last message repeated 1 times
[Mon Jul 8 17:46:19.667 2024] [15] rt: table tbl01: ramchunk saved ok (mode=forced, last TID=1657961461, current TID=1658000187, ram=37.783 Mb, time delta=53 sec, took=0.100 sec)
[Mon Jul 8 17:46:19.781 2024] [52] rt: table tbl02: ramchunk saved ok (mode=forced, last TID=94749496, current TID=94749758, ram=14.861 Mb, time delta=54 sec, took=0.040 sec)
[Mon Jul 8 17:46:19.808 2024] [84] DEBUG: Detached::RemoveThread called for 84
[Mon Jul 8 17:46:19.808 2024] [84] DEBUG: Terminated thread 84, 'alone_4'
[Mon Jul 8 17:46:19.835 2024] [85] DEBUG: Detached::AddThread called for 'alone_5', tid 85
[Mon Jul 8 17:46:19.835 2024] [85] DEBUG: P01: syntax error, unexpected identifier near 'FLUSH ATTRIBUTES'
[Mon Jul 8 17:46:19.835 2024] [85] DEBUG: P03: syntax error, unexpected tablename near 'FLUSH ATTRIBUTES'
[Mon Jul 8 17:46:19.835 2024] [85] DEBUG: attrflush: forcing check, tag=0
[Mon Jul 8 17:46:19.835 2024] [47] DEBUG: attrflush: doing the check
[Mon Jul 8 17:46:19.835 2024] [47] DEBUG: attrflush: no dirty tables found
[Mon Jul 8 17:46:19.835 2024] [85] DEBUG: attrflush: check finished, tag=0
[Mon Jul 8 17:46:19.835 2024] [85] DEBUG: Detached::RemoveThread called for 85
[Mon Jul 8 17:46:19.835 2024] [85] DEBUG: Terminated thread 85, 'alone_5'
[Mon Jul 8 17:46:19.835 2024] [86] DEBUG: Detached::AddThread called for 'alone_6', tid 86
[Mon Jul 8 17:46:19.836 2024] [86] DEBUG: P01: syntax error, unexpected FREEZE near 'FREEZE tbl01'
[Mon Jul 8 17:46:19.836 2024] [86] DEBUG: P03: syntax error, unexpected tablename near 'FREEZE tbl01'
[Mon Jul 8 17:46:19.836 2024] [86] WARNING: got ident_all
[Mon Jul 8 17:46:19.855 2024] [86] DEBUG: Detached::RemoveThread called for 86
[Mon Jul 8 17:46:19.855 2024] [86] DEBUG: Terminated thread 86, 'alone_6'
[Mon Jul 8 17:50:45.858 2024] [36] DEBUG: P01: syntax error, unexpected KILL near 'KILL QUERY 229'
[Mon Jul 8 17:50:45.860 2024] [36] DEBUG: P03: syntax error, unexpected tablename near 'KILL QUERY 229'
[Mon Jul 8 17:50:47.034 2024] [11] DEBUG: P01: syntax error, unexpected KILL near 'KILL 229'
[Mon Jul 8 17:50:47.034 2024] [11] DEBUG: P03: syntax error, unexpected tablename near 'KILL 229'
[Mon Jul 8 17:51:54.140 2024] [87] DEBUG: Detached::AddThread called for 'alone_7', tid 87
[Mon Jul 8 17:51:54.140 2024] [87] DEBUG: P01: syntax error, unexpected UNFREEZE near 'UNFREEZE tbl01'
[Mon Jul 8 17:51:54.140 2024] [87] DEBUG: P03: syntax error, unexpected tablename near 'UNFREEZE tbl01'
[Mon Jul 8 17:51:54.140 2024] [87] WARNING: got ident_all
[Mon Jul 8 17:51:58.598 2024] [31] DEBUG: P01: syntax error, unexpected KILL near 'KILL QUERY 234'
[Mon Jul 8 17:51:58.598 2024] [31] DEBUG: P03: syntax error, unexpected tablename near 'KILL QUERY 234'
[Mon Jul 8 17:51:58.923 2024] [54] DEBUG: P01: syntax error, unexpected KILL near 'KILL 234'
[Mon Jul 8 17:51:58.923 2024] [54] DEBUG: P03: syntax error, unexpected tablename near 'KILL 234'
[Mon Jul 8 17:52:07.052 2024] [88] DEBUG: Detached::AddThread called for 'alone_8', tid 88
[Mon Jul 8 17:52:08.066 2024] [88] DEBUG: Detached::RemoveThread called for 88
[Mon Jul 8 17:52:08.066 2024] [88] DEBUG: Terminated thread 88, 'alone_8'This leaves one process in this state:
strace: Process 221026 attached
pselect6(0, NULL, NULL, NULL, {tv_sec=0, tv_nsec=154724772}, NULL) = 0 (Timeout)
getpid() = 1
gettid() = 1
pselect6(0, NULL, NULL, NULL, {tv_sec=0, tv_nsec=500000000}, NULL) = 0 (Timeout)
...Average load ~ 2000 requests. Usually there are more updates, but there are also selections. I’ll also note that on Ubuntu, under heavy load, the service crashed; it could only work with max_threads_per_query = 1. We switched to Debian.
sanikolaev
commented
1 month ago Average load ~ 2000 requests. Usually there are more updates, but there are also selections.
2000 requests per second, mostly updates?
sanikolaev
commented
1 month ago I've reproduced smth similar when backing up a few gigabytes table under heavy UPDATE load:
2024-07-09 04:48:02 [Info] name...
Fatal error: Uncaught Manticoresearch\Backup\Exception\SearchdException: Failed to send query to the Manticore Search daemon. Ensure that it is set up to listen for HTTP or HTTPS connections and has the appropriate certificates in place. Additionally, check the 'max_connections' setting in the configuration file to ensure that it has not been exceeded. in /usr/share/manticore/modules/manticore-backup/src/Lib/ManticoreClient.php:279
Stack trace:
#0 /usr/share/manticore/modules/manticore-backup/src/Lib/ManticoreClient.php(145): Manticoresearch\Backup\Lib\ManticoreClient->execute('UNFREEZE name')
#1 /usr/share/manticore/modules/manticore-backup/src/Lib/ManticoreClient.php(160): Manticoresearch\Backup\Lib\ManticoreClient->unfreeze(Array)
#2 [internal function]: Manticoresearch\Backup\Lib\ManticoreClient->Manticoresearch\Backup\Lib\{closure}(true, 'name')
#3 /usr/share/manticore/modules/manticore-backup/src/Lib/ManticoreClient.php(157): array_reduce(Array, Object(Closure), true)
#4 /usr/share/manticore/modules/manticore-backup/src/Lib/ManticoreBackup.php(166): Manticoresearch\Backup\Lib\ManticoreClient->unfreezeAll()
#5 [internal function]: Manticoresearch\Backup\Lib\ManticoreBackup::Manticoresearch\Backup\Lib\{closure}(Object(Manticoresearch\Backup\Lib\ManticoreClient))
#6 {main}
thrown in /usr/share/manticore/modules/manticore-backup/src/Lib/ManticoreClient.php on line 279mysql> unfreeze name;is hanging.
Trying to localize.
sanikolaev
commented
1 month ago @srgtest @nxjts
Can you confirm you were updating a string/json attribute when it hanged?
Here's what I've reproduced:
Config:
snikolaev@dev2:~$ cat 116.conf
searchd {
listen = 9315:mysql
listen = 9316
log = searchd.log
pid_file = searchd.pid
data_dir = data
watchdog = 0
}Start searchd:
snikolaev@dev2:~$ searchd -c 116.conf
Manticore 6.3.3 f92db4ac1@24070715 dev (columnar 2.3.1 42f2b06@24070110) (secondary 2.3.1 42f2b06@24070110) (knn 2.3.1 42f2b06@24070110)
Copyright (c) 2001-2016, Andrew Aksyonoff
Copyright (c) 2008-2016, Sphinx Technologies Inc (http://sphinxsearch.com)
Copyright (c) 2017-2024, Manticore Software LTD (https://manticoresearch.com)
[24:48.472] [220367] using config file '/home/snikolaev/116.conf' (140 chars)...
snikolaev@dev2:~$ starting daemon version '6.3.3 f92db4ac1@24070715 dev (columnar 2.3.1 42f2b06@24070110) (secondary 2.3.1 42f2b06@24070110) (knn 2.3.1 42f2b06@24070110)' ...
listening on all interfaces for mysql, port=9315
listening on all interfaces for sphinx and http(s), port=9316Create a table:
mysql -P9315 -h0 -e "drop table if exists t; create table t(s string); insert into t values(1, 'a'); flush ramchunk t"Start UPDATEs:
rm -f /tmp/update.sql; for n in `seq 1 10000`; do echo "update t set s='b' where id=1;" >> /tmp/update.sql; done;
while true; do mysql -P9315 -h0 < /tmp/update.sql | break; echo -n .; done;In another window:
Freeze the table:
mysql -P9315 -h0 -e "freeze t";
+-------------------+-----------------------------------+
| file | normalized |
+-------------------+-----------------------------------+
| data/t/t.0.spa | /home/snikolaev/data/t/t.0.spa |
| data/t/t.0.spb | /home/snikolaev/data/t/t.0.spb |
| data/t/t.0.spd | /home/snikolaev/data/t/t.0.spd |
| data/t/t.0.spe | /home/snikolaev/data/t/t.0.spe |
| data/t/t.0.sph | /home/snikolaev/data/t/t.0.sph |
| data/t/t.0.sphi | /home/snikolaev/data/t/t.0.sphi |
| data/t/t.0.spi | /home/snikolaev/data/t/t.0.spi |
| data/t/t.0.spidx | /home/snikolaev/data/t/t.0.spidx |
| data/t/t.0.spm | /home/snikolaev/data/t/t.0.spm |
| data/t/t.0.spp | /home/snikolaev/data/t/t.0.spp |
| data/t/t.0.spt | /home/snikolaev/data/t/t.0.spt |
| data/t/t.meta | /home/snikolaev/data/t/t.meta |
| data/t/t.ram | /home/snikolaev/data/t/t.ram |
| data/t/t.settings | /home/snikolaev/data/t/t.settings |
+-------------------+-----------------------------------+Attempt unfreezing it:
mysql -P9315 -h0 -e "unfreeze t";
# HANGS hereint instead of string works fineflush ramchunk works finenxjts
commented
1 month ago Most often uint, bigint, mva. Less often json.
Update Jul 9 2024
Likely MRE - https://github.com/manticoresoftware/manticoresearch-backup/issues/116#issuecomment-2216597206
Package versions:
When running the manticore-backup command:
An error appears in the log:
As you can see, the backup itself went through, but at the UNFREEZE stage something went wrong. This happens periodically. At the same time, Manticore itself hangs and accepts more requests, except for a local connection. Solved by:
searchd.log:
Please tell me what is causing this behavior and how to eliminate it?
Ticket on the forum: https://forum.manticoresearch.com/t/manticore-backup-failed-to-send-query-to-the-manticore-search-daemon/1973