Самовольное выключение searchd

General Discussions - Russian
25

Ссылка на полный дебаг во время процесса зависания:
https:// disk.yandex.kz/d/aJSkZxmDsCaprw

Searchd.log был по-прежнему без какой-то релевантной информации о зависании. Включил расширенный режим логов debugv уже после зависания, т.к. сильно засоряются, а когда именно случится зависание неизвестно. Время в приложенном файле логов начинается уже после момента зависания.

При попытке остановить процесс searchd --stopwait ничего не происходит, команда просто зависает.

Конфиг:

common {
    plugin_dir = /usr/local/lib/manticore
}

indexer {
    mem_limit = 1024M
    lemmatizer_cache = 256M
}

searchd {
    listen = 127.0.0.1:9312
    listen = 127.0.0.1:9306:mysql
    listen = 127.0.0.1:9307:mysql_vip
    listen = 127.0.0.1:9308:http
    log = /var/log/manticore/searchd.log
    query_log = /var/log/manticore/query.log
    pid_file = /var/run/manticore/searchd.pid
    data_dir = /var/lib/manticore
    query_log_format = sphinxql
    expansion_limit = 16
    max_threads_per_query = 4
}
26

В [Thu Nov 16 16:23:40.460 2023] принудительно завершил процесс, перезапустил. И снова, внешне команда запуска как-будто нормально отработала.

Процесс демона запущен, но он не работает, при проверке статуса searchd --status выдает все ту же ошибку:

Manticore 6.2.12 dc5144d35@230822 (columnar 2.2.4 5aec342@230822) (secondary 2.2.4 5aec342@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)

[27:07.612] [2747544] using config file '/etc/manticoresearch/manticore.conf' (515 chars)...
[27:07.614] [2747544] WARNING: failed to connect to 127.0.0.1:9312: Connection refused

[27:07.614] [2747544] FATAL: failed to connect to daemon: please specify listen with sphinx protocol in your config file

По ссылке прикладываю логи searchd.log уже в процессе перезапуска:
https:// disk.yandex.kz/d/a50pEbbwuidIdA

27

В [Thu Nov 16 16:46:46.686 2023] удалил папку /binlog и успешно перезапустил демона.

Прикладываю также дополненные логи searchd.log:
https:// disk.yandex.kz/d/6xgxHte2XqZ0Tg

28

Спасибо. Посмотрим. А с dev версией проблема повторяется? Manticore Search Manual

29

Dev версию не проверял)

30

Можете проверить?

31

Так, чтобы проверка имела смысл, наверное не получится, т.к. для этого придется ставить dev версию движка на прод…

32

Сейчас был случай, когда без удаления /binlog запустилось (но также с принудительным завершением зависшего процесса).

33

Судя по логу, который вы давали, и 16-го нормально стартануло с бинлогом:

[Thu Nov 16 16:26:45.699 2023] [2747511] listening on 127.0.0.1:9308 for sphinx and http(s)
[Thu Nov 16 16:26:52.244 2023] [2747516] binlog: replaying log /var/lib/manticore/binlog/binlog.001
[Thu Nov 16 16:27:44.959 2023] [2747512] binlog: table products_keywords: recovered from tid 343752 to tid 343873
...
[Thu Nov 16 16:27:44.964 2023] [2747512] binlog: finished replaying total 1 in 52.720 sec
[Thu Nov 16 16:27:44.967 2023] [2747513] prereading 404 tables
[Thu Nov 16 16:27:45.031 2023] [2747511] accepting connections
[Thu Nov 16 16:27:45.280 2023] [2747513] preread 404 tables in 0.313 sec
[Thu Nov 16 16:27:45.288 2023] [2747514] [BUDDY] started v1.0.18 '/usr/share/manticore/modules/manticore-buddy/bin/manticore-buddy --listen=http://127.0.0.1:9312  --threads=8' at http://127.0.0.1:37259
[Thu Nov 16 16:27:45.422 2023] [2747516] [BUDDY] Loaded plugins:
[Thu Nov 16 16:27:45.422 2023] [2747516] [BUDDY]   core: empty-string, backup, emulate-elastic, insert, select, show, cli-table, plugin, test, insert-mva
[Thu Nov 16 16:27:45.422 2023] [2747516] [BUDDY]   local: 
[Thu Nov 16 16:27:45.422 2023] [2747516] [BUDDY]   extra: 
[Thu Nov 16 16:46:46.686 2023] [2748950] watchdog: main process 2748951 forked ok
[Thu Nov 16 16:46:46.704 2023] [2748951] starting daemon version '6.2.12 dc5144d35@230822 (columnar 2.2.4 5aec342@230822) (secondary 2.2.4 5aec342@230822)' ...
[Thu Nov 16 16:46:46.704 2023] [2748951] listening on 127.0.0.1:9312 for sphinx and http(s)

Может вы просто не дожидаетесь, пока бинлог проиграется и поэтому считаете, что без очистки бинлога не стартует?

34

Хмм, ну я долго жду обычно. Когда не знал, что удаление binlog помогает, так вообще времени с хорошим запасом было, пока пытался понять в чем дело.

35

Хотелось бы увидеть searchd log вокруг момента, когда без удаления бинлога не запустилось.

36

Сейчас опять завис, процесс убил, перезапустил без удаления /binlog. Но он тут же запустился, когда все ок, ждать не приходится.

В общем, как требовалось залогировать не получилось, но на всякий случай прикладываю:
https:// disk.yandex.kz/d/a50pEbbwuidIdA

Попытка выключения --stopwait
[Wed Nov 22 09:08:53.559 2023] [3210079]

Запустил (после принудительного завершения)
[Wed Nov 22 09:27:57.767 2023] [3282978]

37

Получилось поймать момент зависания с включенным режимом дебага debugv, зависло примерно в районе 9:10:

https:// disk.yandex.kz/d/HqnAqFZoB4dFpA

С тем, что не дожидаюсь подгрузки binlog кажется вы правы, сейчас больше времени решил подождать после перезапуска. Сначала --status выдавал всё ту же ошибку

FATAL: failed to connect to daemon: please specify listen with sphinx protocol in your config file,

но потом заработало.

38

Получилось поймать момент зависания с включенным режимом дебага debugv, зависло примерно в районе 9:10:

А есть query log?

39

Да
https:// disk.yandex.kz/d/JluDyxezEGXWUg

40

зависло примерно в районе 9:10:

Судя по query log, запросы активно шли до Nov 23 09:16:04.883

И в searchd log’е видно:

[Thu Nov 23 09:16:10.402 2023] [3300328] caught SIGTERM, shutting down
[Thu Nov 23 09:16:13.893 2023] [3300348] DEBUG: got events=1, tick=12450525, interrupted=1
[Thu Nov 23 09:21:31.762 2023] [3362312] watchdog: main process 3362313 forked ok
[Thu Nov 23 09:21:31.776 2023] [3362313] starting daemon version '6.2.12 dc5144d35@230822 (columnar 2.2.4 5aec342@230822) (secondary 2.2.4 5aec342@230822)' ...
[Thu Nov 23 09:21:31.776 2023] [3362313] listening on 127.0.0.1:9312 for sphinx and http(s)

Т.е. в 09:16 вы сделали systemctl stop manticore или типа того, после этого оно зависло и потом уже вы прибили запрос, верно?

41

Да, это возможно, я время примерно сказал.

Нет, это я уже руками выключал --stopwait. Зависло, получается, где-то за пару минут до этого. Вот кажется в логах никак это не отражается…

Т.е. зависло, я в 09:16 попытался выключить нормально, команда не отработала, я ее отменил. И потом уже прибил демона через sudo kill -9.

42

попытался выключить нормально

Ну вот в этот момент по идее в логе должно быть видно caught SIGTERM, shutting down и это и видно в данном случае. Проблема в том, что после этого должны быть ещё строки и в конце что-то типа:

[Thu Nov 23 10:03:24.893 2023] [1566736] shutdown daemon version '6.2.13 cf6ec3bfd@231121 dev (columnar 2.2.5 975172c@231117) (secondary 2.2.5 975172c@231117) (knn 2.2.5 975172c@231117)' ...
[Thu Nov 23 10:03:24.895 2023] [1566736] shutdown complete
43

А сколько у вас таблиц в мантикоре?

44

404 таблицы