Как завести mysql (Ошибка 9 Bad file descriptor)?

Question

[animanshnik]

Добрый день, в один светлый денек, после перезапуска mysql, он не завелся
systemctl:

● mysql.service - MySQL Community Server
     Loaded: loaded (/lib/systemd/system/mysql.service; enabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Fri 2022-01-21 19:34:13 UTC; 3min 53s ago
    Process: 2838586 ExecStartPre=/usr/share/mysql/mysql-systemd-start pre (code=exited, status=0/SUCCESS)
    Process: 2838594 ExecStart=/usr/sbin/mysqld (code=exited, status=1/FAILURE)
   Main PID: 2838594 (code=exited, status=1/FAILURE)
     Status: "Server startup in progress"
      Error: 9 (Bad file descriptor)

янв 21 19:34:13 my-new-server systemd[1]: mysql.service: Main process exited, code=exited, status=1/FAILURE
янв 21 19:34:13 my-new-server systemd[1]: mysql.service: Failed with result 'exit-code'.
янв 21 19:34:13 my-new-server systemd[1]: Failed to start MySQL Community Server.
янв 21 19:34:13 my-new-server systemd[1]: mysql.service: Scheduled restart job, restart counter is at 5.
янв 21 19:34:13 my-new-server systemd[1]: Stopped MySQL Community Server.
янв 21 19:34:13 my-new-server systemd[1]: mysql.service: Start request repeated too quickly.
янв 21 19:34:13 my-new-server systemd[1]: mysql.service: Failed with result 'exit-code'.
янв 21 19:34:13 my-new-server systemd[1]: Failed to start MySQL Community Server.

Логи пустые, в journalctl -xe тоже нет никакой полезной информации. Сбился уже, как фиксить?

Answer 1

[Immortal_pony]

Для начала попробуйте надёжно перезапустить:

service mysql stop
killall -KILL mysql mysqld_safe mysqld
service mysql start

Если не поможет, то приложите логи, которые в journalctl. Может мы углядим какую полезную информацию.
И данные /var/log/mysqld.log тоже приложите.

Ну и mysqld_safe попробуйте и уточните, заводится в safe mode или нет

Comments

[Alfieros]

В один светлый денёк всё не может сломаться, если до этого работало. Мб последовательность действий, апгрейдов и т.д?

[animanshnik]

При запуске mysqld_safe выводит:

2022-01-22T06:08:51.977947Z mysqld_safe Logging to '/var/log/mysqld.log'.
2022-01-22T06:08:51.994220Z mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
2022-01-22T06:08:52.363756Z mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

UPD: Появился mysqld.log, но он пустой

killall не сработает, ведь оно даже не запускается
UPD: Не сработало

jorunal -xe

root@my-new-server:~# service mysql start
Job for mysql.service failed because the control process exited with error code.
See "systemctl status mysql.service" and "journalctl -xe" for details.
root@my-new-server:~# journalctl -xe
-- Subject: Ошибка юнита mysql.service
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Произошел сбой юнита mysql.service.
--
-- Результат: failed.
янв 22 06:11:17 my-new-server systemd[1]: mysql.service: Scheduled restart job, restart counter is at 1.
-- Subject: Назначен автоматический перезапуск юнита
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Назначен автоматический перезапуск юнита mysql.service, так как для него был задан
-- параметр Restart=.
янв 22 06:11:17 my-new-server systemd[1]: Stopped MySQL Community Server.
-- Subject: Завершена остановка юнита mysql.service.
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Процесс остановки юнита mysql.service был завершен.
янв 22 06:11:17 my-new-server systemd[1]: Starting MySQL Community Server...
-- Subject: Начинается запуск юнита mysql.service
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Начат процесс запуска юнита mysql.service.
янв 22 06:11:17 my-new-server audit[2851267]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/lib/mysql/mysqld_tmp_file_case_insensitive_test.lower-test" pid=2851267 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
янв 22 06:11:17 my-new-server kernel: audit: type=1400 audit(1642831877.139:6946): apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/lib/mysql/mysqld_tmp_file_case_insensitive_test.lower-test" pid=2851267 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
янв 22 06:11:17 my-new-server audit[2851268]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/lib/mysql/mysqld_tmp_file_case_insensitive_test.lower-test" pid=2851268 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=122 ouid=122
янв 22 06:11:17 my-new-server audit[2851268]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/lib/mysql/mysqld_tmp_file_case_insensitive_test.lower-test" pid=2851268 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=122 ouid=122
янв 22 06:11:17 my-new-server audit[2851268]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/log/mysql/error.log" pid=2851268 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=122 ouid=122
янв 22 06:11:17 my-new-server audit[2851268]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/log/mysql/error.log" pid=2851268 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=122 ouid=122
янв 22 06:11:17 my-new-server audit[2851268]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/log/mysql/error.log" pid=2851268 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=122 ouid=122
янв 22 06:11:17 my-new-server audit[2851268]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/log/mysql/error.log" pid=2851268 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=122 ouid=122
янв 22 06:11:17 my-new-server audit[2851268]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/log/mysql/error.log" pid=2851268 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=122 ouid=122
янв 22 06:11:17 my-new-server audit[2851268]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/log/mysql/error.log" pid=2851268 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=122 ouid=122
янв 22 06:11:17 my-new-server systemd[1]: mysql.service: Main process exited, code=exited, status=1/FAILURE
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- An ExecStart= process belonging to unit mysql.service has exited.
--
-- The process' exit code is 'exited' and its exit status is 1.
янв 22 06:11:17 my-new-server systemd[1]: mysql.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- The unit mysql.service has entered the 'failed' state with result 'exit-code'.
янв 22 06:11:17 my-new-server systemd[1]: Failed to start MySQL Community Server.
-- Subject: Ошибка юнита mysql.service
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Произошел сбой юнита mysql.service.
--
-- Результат: failed.
янв 22 06:11:17 my-new-server systemd[1]: mysql.service: Scheduled restart job, restart counter is at 2.
-- Subject: Назначен автоматический перезапуск юнита
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Назначен автоматический перезапуск юнита mysql.service, так как для него был задан
-- параметр Restart=.
янв 22 06:11:17 my-new-server systemd[1]: Stopped MySQL Community Server.
-- Subject: Завершена остановка юнита mysql.service.
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Процесс остановки юнита mysql.service был завершен.
янв 22 06:11:17 my-new-server systemd[1]: Starting MySQL Community Server...
-- Subject: Начинается запуск юнита mysql.service
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Начат процесс запуска юнита mysql.service.
янв 22 06:11:17 my-new-server audit[2851276]: AVC apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/mnt/vdb1/var/lib/mysql/mysqld_tmp_file_case_insensitive_test.lower-test" pid=2851276 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0

[animanshnik]

Alfieros, Вроде ничего сверхвыдающегося не делал, у меня просто место на хосте закончилось, поэтому все легло, а вот mysql обратно не встал..

[Alfieros]

animanshnik, У тебя нет к БД доступа. Весь лог можно не скидывать. Хватает первых строк... Хуй знает что там у тебя запрашивает, но, факт того что сервер не откликается при запросе. Лови ошибку на этом этапе...

[animanshnik]

Alfieros, Я думал над этим, и права выдавал (на этот вопрос у гугла были ответы), это странно. Сижу через рут, права быть должны

[animanshnik]

Alfieros, если ты говоришь про то, где было password root not entered (или что-то такое), это не от mysql ошибка, по идее. А больше ошибок доступа я в журнале не вижу

[Alfieros]

- Результат: done.
янв 22 06:11:06 my-new-server sshd[2851126]: Failed password for root from 122.194.229.40 port 61356 ssh2

Я что-то не заметил... Пароль введи верный, и всё будет ок!

[animanshnik]

Alfieros, Но я уже подключен по ssh, куда его вводить то? :D, это не мой сеанс, как я понял

[Alfieros]

animanshnik, sudo

[animanshnik]

Alfieros, Нет, первым делом попробовал. Ошибка не меняется

--
-- The process' exit code is 'exited' and its exit status is 1.
янв 22 06:35:54 my-new-server systemd[1]: mysql.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- The unit mysql.service has entered the 'failed' state with result 'exit-code'.
янв 22 06:35:54 my-new-server systemd[1]: Failed to start MySQL Community Server.
-- Subject: Ошибка юнита mysql.service
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Произошел сбой юнита mysql.service.
--
-- Результат: failed.
янв 22 06:35:55 my-new-server systemd[1]: mysql.service: Scheduled restart job, restart counter is at 5.
-- Subject: Назначен автоматический перезапуск юнита
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Назначен автоматический перезапуск юнита mysql.service, так как для него был задан
-- параметр Restart=.
янв 22 06:35:55 my-new-server systemd[1]: Stopped MySQL Community Server.
-- Subject: Завершена остановка юнита mysql.service.
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Процесс остановки юнита mysql.service был завершен.
янв 22 06:35:55 my-new-server systemd[1]: mysql.service: Start request repeated too quickly.
янв 22 06:35:55 my-new-server systemd[1]: mysql.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- The unit mysql.service has entered the 'failed' state with result 'exit-code'.
янв 22 06:35:55 my-new-server systemd[1]: Failed to start MySQL Community Server.
-- Subject: Ошибка юнита mysql.service
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Произошел сбой юнита mysql.service.
--
-- Результат: failed.
lines 1852-1895/1895 (END)
--
-- The process' exit code is 'exited' and its exit status is 1.
янв 22 06:35:54 my-new-server systemd[1]: mysql.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- The unit mysql.service has entered the 'failed' state with result 'exit-code'.
янв 22 06:35:54 my-new-server systemd[1]: Failed to start MySQL Community Server.
-- Subject: Ошибка юнита mysql.service
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Произошел сбой юнита mysql.service.
--
-- Результат: failed.
янв 22 06:35:55 my-new-server systemd[1]: mysql.service: Scheduled restart job, restart counter is at 5.
-- Subject: Назначен автоматический перезапуск юнита
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Назначен автоматический перезапуск юнита mysql.service, так как для него был задан
-- параметр Restart=.
янв 22 06:35:55 my-new-server systemd[1]: Stopped MySQL Community Server.
-- Subject: Завершена остановка юнита mysql.service.
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Процесс остановки юнита mysql.service был завершен.
янв 22 06:35:55 my-new-server systemd[1]: mysql.service: Start request repeated too quickly.
янв 22 06:35:55 my-new-server systemd[1]: mysql.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- The unit mysql.service has entered the 'failed' state with result 'exit-code'.
янв 22 06:35:55 my-new-server systemd[1]: Failed to start MySQL Community Server.
-- Subject: Ошибка юнита mysql.service
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Произошел сбой юнита mysql.service.
--
-- Результат: failed.

[Immortal_pony]

Alfieros , animanshnik , вы там разобрались в чём дело было? Если да, то опубликуйте ответ или сюда информацию скиньте - я в свой докину.

Что касается логов, то я вижу сральник apparmor'а при старте, похоже что эта редиска не даёт мускулю доступа к его же файлам. Вот статья про эту печаль: https://warlord0blog.wordpress.com/2018/01/18/mysq...
Собственно, там и решение есть - поправить конфиг apparmor'а:

sudo vi /etc/apparmor.d/usr.sbin.mysqld

...
  /etc/mysql/mysql.conf.d/ r,
  /etc/mysql/mysql.conf.d/* r,
  /sys/devices/system/node/* r,
  /etc/mysql/*.cnf r,
  /run/mysqld/* rw,
...

$ sudo systemctl reload apparmor.service
$ sudo systemctl start mysql.service

[animanshnik]

Immortal_pony, проблема решена не была, я смирился. Но ваш метод попробую. Может поможет...

[Immortal_pony]

animanshnik ну как оно там? Мы тут все пыржеваем за тебя

[animanshnik]

Immortal_pony, Зависает на старте mysql

[animanshnik]

Immortal_pony,

mysql.service - MySQL Community Server
     Loaded: loaded (/lib/systemd/system/mysql.service; enabled; vendor preset: enabled)
     Active: activating (start) since Tue 2022-01-25 21:23:54 UTC; 1s ago
    Process: 877834 ExecStartPre=/usr/share/mysql/mysql-systemd-start pre (code=exited, status=0/SUCCESS)
   Main PID: 877842 (mysqld)
     Status: "Server startup in progress"
      Tasks: 18 (limit: 2274)
     Memory: 328.5M
     CGroup: /system.slice/mysql.service
             └─877842 /usr/sbin/mysqld

янв 25 21:23:54 my-new-server systemd[1]: Starting MySQL Community Server...

[Immortal_pony]

animanshnik а в логах что-то есть?

[animanshnik]

Immortal_pony, error log появился

2022-01-26T06:01:32.706985Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.27-0ubuntu0.20.04.1) starting as process 889371
2022-01-26T06:01:32.721085Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-01-26T06:01:33.742259Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2022-01-26T06:01:34.227256Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1 is enabled for channel mysql_main
2022-01-26T06:01:34.227337Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1.1 is enabled for channel mysql_main
2022-01-26T06:01:34.229526Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2022-01-26T06:01:34.229632Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2022-01-26T06:01:34.248343Z 0 [ERROR] [MY-000067] [Server] unknown variable 'old_passwords=1'.
2022-01-26T06:01:34.249059Z 0 [ERROR] [MY-010119] [Server] Aborting
2022-01-26T06:01:35.580251Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.27-0ubuntu0.20.04.1)  (Ubuntu).
2022-01-26T06:01:36.293231Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.27-0ubuntu0.20.04.1) starting as process 889418
2022-01-26T06:01:36.307734Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-01-26T06:01:37.169346Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2022-01-26T06:01:37.505961Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1 is enabled for channel mysql_main
2022-01-26T06:01:37.506907Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1.1 is enabled for channel mysql_main
2022-01-26T06:01:37.509403Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2022-01-26T06:01:37.509515Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2022-01-26T06:01:37.535267Z 0 [ERROR] [MY-000067] [Server] unknown variable 'old_passwords=1'.
2022-01-26T06:01:37.536082Z 0 [ERROR] [MY-010119] [Server] Aborting
2022-01-26T06:01:38.905887Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.27-0ubuntu0.20.04.1)  (Ubuntu).
2022-01-26T06:01:39.757345Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.27-0ubuntu0.20.04.1) starting as process 889464
2022-01-26T06:01:39.768995Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-01-26T06:01:40.491621Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2022-01-26T06:01:41.045483Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1 is enabled for channel mysql_main
2022-01-26T06:01:41.045520Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1.1 is enabled for channel mysql_main
2022-01-26T06:01:41.046367Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2022-01-26T06:01:41.046403Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2022-01-26T06:01:41.058650Z 0 [ERROR] [MY-000067] [Server] unknown variable 'old_passwords=1'.
2022-01-26T06:01:41.058993Z 0 [ERROR] [MY-010119] [Server] Aborting

[Immortal_pony]

animanshnik unknown variable 'old_passwords=1'.
Похоже на корень зла. Посмотрите к конфигах mysql - выглядит будто там указана переменная old_passwords=1. Это очень старый параметр и современные версии mysql о таком не знают.

[animanshnik]

Immortal_pony, Странно, сервис запустился, но
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)
При этом пароль правильный

[Immortal_pony]

[mysqld]
default-authentication-plugin=mysql_native_password

Попробуйте прописать это в конфиге и перезапустить сервис.
Если не получится, то зайдите через mysqld_safe --skip-grant-tables (в это режиме вы сможете зайти рутом без пароля) и пересоздайте пользователей

[animanshnik]

Immortal_pony,
mysqld_safe мне выдает

2022-01-28T06:51:17.503789Z mysqld_safe Logging to '/var/log/mysqld.log'.
2022-01-28T06:51:17.520136Z mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
2022-01-28T06:51:17.932275Z mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

И после этого ничего не меняется.
native_password тоже не помог

[Immortal_pony]

animanshnik
Убедитесь что папка есть и у mysql права на запись в неё есть

mkdir -p /var/run/mysqld
chown mysql:mysql /var/run/mysqld

Потом ещё раз mysqld_safe

[animanshnik]

screen

Расширения вот такие, все равно не создает
(Кстати, по наличию папки, при выключении mysql он удаляет ее)

UPD: В папке лежат mysqlx.soc, mysqld он создавать не хочет

[animanshnik]

Immortal_pony, Вроде починил, но теперь опять bad file descriptor вылез

[animanshnik]

animanshnik, И даже перезагрузка apparmor не особо помогла

[Immortal_pony]

animanshnik На этом этапе я бы уже просто переустановил mysql целиком, а то и всю виртуалку )
Что в итоге сделали?))

[animanshnik]

Immortal_pony, Смирился и расслабился :)