Заметка] /usr/sbin/mysqld (инициировано: неизвестно): Обычное завершение работы

2020-10-01 18:30:05 0 [Note] /usr/sbin/mysqld (initiated by: unknown): Normal shutdown
2020-10-01 18:30:05 0 [Note] Event Scheduler: Purging the queue. 0 events
2020-10-01 18:30:05 0 [Note] InnoDB: FTS optimize thread exiting.
2020-10-01 18:30:05 0 [Note] InnoDB: Starting shutdown...
2020-10-01 18:30:05 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2020-10-01 18:30:05 0 [Note] InnoDB: Instance 0, restricted to 2048 pages due to innodb_buf_pool_dump_pct=25
2020-10-01 18:30:05 0 [Note] InnoDB: Buffer pool(s) dump completed at 201001 18:30:05
2020-10-01 18:30:07 0 [Note] InnoDB: Shutdown completed; log sequence number 11518008272; transaction id 28700995
2020-10-01 18:30:07 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-10-01 18:30:07 0 [Note] /usr/sbin/mysqld: Shutdown complete

Что-то или какой-то процесс вызывает отключение сервера MySQL, но я не знаю, что именно.

Я использую:

Debian 10
mysql Ver 15.1 Distrib 10.3.23-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2

Когда сервер запустился:

2020-10-01 18:40:42 0 [Note] InnoDB: Using Linux native AIO
2020-10-01 18:40:42 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-10-01 18:40:42 0 [Note] InnoDB: Uses event mutexes
2020-10-01 18:40:42 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-10-01 18:40:42 0 [Note] InnoDB: Number of pools: 1
2020-10-01 18:40:42 0 [Note] InnoDB: Using SSE2 crc32 instructions
2020-10-01 18:40:42 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2020-10-01 18:40:42 0 [Note] InnoDB: Completed initialization of buffer pool
2020-10-01 18:40:42 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-10-01 18:40:42 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2020-10-01 18:40:42 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-10-01 18:40:42 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-10-01 18:40:42 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-10-01 18:40:42 0 [Note] InnoDB: 10.3.23 started; log sequence number 11518008272; transaction id 28700996
2020-10-01 18:40:42 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2020-10-01 18:40:42 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-10-01 18:40:42 0 [Note] Server socket created on IP: '127.0.0.1'.
2020-10-01 18:40:42 0 [Note] Reading of all Master_info entries succeeded
2020-10-01 18:40:42 0 [Note] Added new Master_info '' to hash table
2020-10-01 18:40:42 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.3.23-MariaDB-0+deb10u1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Debian 10
2020-10-01 18:40:42 0 [Note] InnoDB: Buffer pool(s) load completed at 201001 18:40:42

Я перезапустил сервер, и проблема была решена

¯_(ツ)_/¯

Для других пользователей, которых сюда направила интернет-поисковая система:
У меня та же проблема возникла в контейнере Proxmox 8.2.2 LXC, работающем под управлением Ubuntu 20.04, после того как я клонировал его (у всех клонов была одна и та же проблема, поэтому я знал, что это что-то общее, связанное с клонированием).

Та же диагностика, как и выше – неизвестный сигнал убивает поток mysqld, пока он запускается, без явных подсказок, а только с множеством ложных следов. Например, отладка journalctl:

systemd[1]: mariadb.service: Child pid belongs to mariadb.service.
systemd[1]: mariadb.service: Main process exited, code=killed, status=11/SEGV
systemd[1]: mariadb.service: Failed with result 'signal'.
systemd[1]: mariadb.service: Service will restart (restart setting)
systemd[1]: mariadb.service: Changed start -> failed
systemd[1]: mariadb.service: Job pid mariadb.service/start finished, result=failed
systemd[1]: Failed to start MariaDB 10.3.39 database server.

Сначала я изучал элементы, зарегистрированные как ошибки, такие как:

PR_SET_MM_ARG_START failed, attempting PR_SET_MM_ARG_END hack: Operation not permitted

или

mariadb.service: Kernel keyring not supported, ignoring.

Но все это не было проблемой. Также пробовал предположения о необходимости изменить файл переопределения юнита systemd для mariadb, такие как:

# Расширить таймаут запуска юнита

TimeoutSec=900

# Настройка для запуска в LXC контейнере с отсутствующими разрешениями и параметрами ядра

PrivateDevices=false

# Увеличение вывода отладочной информации для нахождения SEGFAULT при запуске

Environment=SYSTEMD_LOG_LEVEL=debug

Но в конце концов это оказался Apparmor. Клонирование контейнера делает профиль Apparmor недействительным, и даже если я сбрасывал его, зайдя в контейнер после запуска, похоже, первый запуск mysqld или какой-то дочерний поток mysqld, который все еще выполнялся, как-то снова делал его недействительным. Решением было полностью остановить процесс mariadb mysqld и все потоки, а затем снова сбросить профиль Apparmor.

Резюме решения:

1. Остановите юнит mariadb и отключите, затем перезагрузите контейнер, чтобы убедиться, что никакие потоки mysqld не выполняются.
2. Очистите профиль Apparmor, затем включите и успешно запустите сервис mariadb.

Команды CLI от имени root (или добавьте префикс sudo):

#> systemctl stop mariadb.service
#> systemctl disable mariadb.service
...
Перезагрузите сервер...
...
#> echo "/usr/sbin/mysqld { }" > /etc/apparmor.d/usr.sbin.mysqld
#> apparmor_parser -v -R /etc/apparmor.d/usr.sbin.mysqld
#> systemctl start mariadb.service
#> systemctl enable mariadb.service