无法启用MySQL bin日志

Question

我有一个MySQL 5.7.22服务器，在启用bin日志时遇到了问题。从我的读取中可以看出，我有适当的配置来启用bin日志，但它们从未在服务器上任何地方创建。我的操作系统是Ubuntu16.04.5LTS，所有补丁都是几天前的最新版本。

这是我的配置，注释去掉了：

[mysqld_safe]
socket      = /var/run/mysqld/mysqld.sock
nice        = 0

[mysqld]
user        = mysql
pid-file    = /var/run/mysqld/mysqld.pid
socket      = /var/run/mysqld/mysqld.sock
port        = 3306
basedir     = /usr
datadir     = /var/lib/mysql
tmpdir      = /tmp
lc-messages-dir = /usr/share/mysql
skip-external-locking
bind-address        = 0.0.0.0
key_buffer_size     = 16M
max_allowed_packet  = 16M
thread_stack        = 192K
thread_cache_size       = 8
myisam-recover-options  = BACKUP
query_cache_limit   = 1M
query_cache_size        = 16M
log_error = /var/log/mysql/error.log
server-id       = 1
log_bin         = /var/log/mysql/mysql-bin.log
expire_logs_days    = 10
max_binlog_size   = 100M
innodb_strict_mode = 0
innodb_log_file_size = 512M
innodb_log_buffer_size = 800M
innodb_file_format = Barracuda

下面是应该写入日志的文件夹，包括在这里显示(希望)正确的权限：

ll /var/log/mysql
total 116
drwxr-s---  2 mysql adm     4096 Jul 23 18:51 ./
drwxrwxr-x 24 root  syslog 12288 Jul 23 19:08 ../
-rw-r-----  1 mysql adm    14622 Jul 23 19:17 error.log
-rw-r-----  1 mysql adm       20 Jul 22 06:25 error.log.1.gz
-rw-r-----  1 mysql adm       20 Jul 21 06:25 error.log.2.gz
-rw-r-----  1 mysql adm       20 Jul 20 06:25 error.log.3.gz
-rw-r-----  1 mysql adm       20 Jul 19 06:25 error.log.4.gz
-rw-r-----  1 mysql adm       20 Jul 18 06:25 error.log.5.gz
-rw-r-----  1 mysql adm       20 Jul 17 06:25 error.log.6.gz
-rw-r-----  1 mysql adm       20 Jul 16 06:25 error.log.7.gz
-rw-r-----  1 mysql adm        0 Jul 23 06:25 general-query.log
-rw-r-----  1 mysql adm       20 Jul 22 06:25 general-query.log.1.gz
-rw-r-----  1 mysql adm       20 Jul 21 06:25 general-query.log.2.gz
-rw-r-----  1 mysql adm       20 Jul 20 06:25 general-query.log.3.gz
-rw-r-----  1 mysql adm       20 Jul 19 06:25 general-query.log.4.gz
-rw-r-----  1 mysql adm       20 Jul 18 06:25 general-query.log.5.gz
-rw-r-----  1 mysql adm       20 Jul 17 06:25 general-query.log.6.gz
-rw-r-----  1 mysql adm       20 Jul 16 06:25 general-query.log.7.gz
-rw-r-----  1 mysql adm        0 Jul 23 06:25 slow-query.log
-rw-r-----  1 mysql adm       20 Jul 22 06:25 slow-query.log.1.gz
-rw-r-----  1 mysql adm       20 Jul 21 06:25 slow-query.log.2.gz
-rw-r-----  1 mysql adm       20 Jul 20 06:25 slow-query.log.3.gz
-rw-r-----  1 mysql adm       20 Jul 19 06:25 slow-query.log.4.gz
-rw-r-----  1 mysql adm       20 Jul 18 06:25 slow-query.log.5.gz
-rw-r-----  1 mysql adm       20 Jul 17 06:25 slow-query.log.6.gz
-rw-r-----  1 mysql adm       20 Jul 16 06:25 slow-query.log.7.gz

您将看到，自今晨(2018年7月23日)起，配置文件中的其他日志已正确编写，因此似乎排除了导致此问题的权限。

最后，我将包括重新启动MySQL时出现的syslog条目。有一行可能与这个问题有关，也可能与此无关，所以我想把它包括进去。

Jul 23 20:12:40 servername systemd[1]: Starting MySQL Community Server...
Jul 23 20:12:40 servername kernel: [1554544.315682] audit: type=1400 audit(1532391160.325:191): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/proc/61396/status" pid=61396 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=106 ouid=106
Jul 23 20:12:40 servername kernel: [1554544.320121] audit: type=1400 audit(1532391160.333:192): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/" pid=61396 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=106 ouid=0
Jul 23 20:12:40 servername kernel: [1554544.323791] audit: type=1400 audit(1532391160.333:193): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/proc/61396/status" pid=61396 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=106 ouid=106
Jul 23 20:12:40 servername kernel: [1554544.499446] audit: type=1400 audit(1532391160.509:194): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/proc/61411/status" pid=61411 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=33 ouid=33
Jul 23 20:12:40 servername kernel: [1554544.504121] audit: type=1400 audit(1532391160.517:195): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/" pid=61411 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=33 ouid=0
Jul 23 20:12:40 servername kernel: [1554544.504342] audit: type=1400 audit(1532391160.517:196): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/proc/61411/status" pid=61411 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=33 ouid=33
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.341787Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000)
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.341876Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000)
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.575763Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.578797Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.22-0ubuntu0.16.04.1) starting as process 61396 ...
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.585237Z 0 [Note] InnoDB: PUNCH HOLE support available
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.585731Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.586180Z 0 [Note] InnoDB: Uses event mutexes
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.586199Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.586216Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.586223Z 0 [Note] InnoDB: Using Linux native AIO
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.586668Z 0 [Note] InnoDB: Number of pools: 1
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.586858Z 0 [Note] InnoDB: Using CPU crc32 instructions
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.592103Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.606427Z 0 [Note] InnoDB: Completed initialization of buffer pool
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.610373Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
Jul 23 20:12:40 servername mysqld[61396]: 2018-07-24T00:12:40.674303Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.074725Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.075824Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.103852Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.106228Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.106812Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.107813Z 0 [Note] InnoDB: Waiting for purge to start
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.158566Z 0 [Note] InnoDB: 5.7.22 started; log sequence number 9047719533
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.158927Z 0 [Note] Plugin 'FEDERATED' is disabled.
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.163763Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.174954Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.176327Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.176959Z 0 [Note] IPv6 is available.
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.177504Z 0 [Note]   - '::' resolves to '::';
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.178084Z 0 [Note] Server socket created on IP: '::'.
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.297940Z 0 [Note] Event Scheduler: Loaded 0 events
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.298812Z 0 [Note] /usr/sbin/mysqld: ready for connections.
Jul 23 20:12:41 servername mysqld[61396]: Version: '5.7.22-0ubuntu0.16.04.1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Ubuntu)
=====>Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.351040Z 2  [Note] Access denied for user 'root'@'localhost' (using password: NO)
Jul 23 20:12:41 servername systemd[1]: Started MySQL Community Server.
Jul 23 20:12:41 servername mysqld[61396]: 2018-07-24T00:12:41.718190Z 0 [Note] InnoDB: Buffer pool(s) load completed at 180723 20:12:41

在由箭头指示的第41行中，有东西试图以root用户身份登录，而不使用密码。我不知道是什么原因。正如我所说，这可能与我的bin日志问题无关。

任何帮助都是非常感谢的。

应Kernelv5 5‘S请求添加如下：

下面是显示bin日志状态的MySQL的输出：

`mysql> show variables like "%log_bin%";
+---------------------------------+-------+
| Variable_name                   | Value |
+---------------------------------+-------+
| log_bin                         | OFF   |
| log_bin_basename                |       |
| log_bin_index                   |       |
| log_bin_trust_function_creators | OFF   |
| log_bin_use_v1_row_events       | OFF   |
| sql_log_bin                     | ON    |
+---------------------------------+-------+
6 rows in set (0.00 sec)`

Answer 1

请与我分享你的最终产出。下面的例子。

mysql> show variables like "%log_bin%";
+---------------------------------+--------------------------------+
| Variable_name                   | Value                          |
+---------------------------------+--------------------------------+
| log_bin                         | ON                             |
| log_bin_basename                | /var/lib/mysql/mysql-bin       |
| log_bin_index                   | /var/lib/mysql/mysql-bin.index |
| log_bin_trust_function_creators | OFF                            |
| log_bin_use_v1_row_events       | OFF                            |
| sql_log_bin                     | ON                             |
+---------------------------------+--------------------------------+
6 rows in set (0.00 sec)

Answer 2

最后，我不得不删除并重新安装MySQL。我不知道是什么引起了这个问题，但一个干净的安装修复了它。

apt remove -y mysql-*
apt purge -y mysql-*
apt install -y mysql-server
mysql_secure_installation

在清除过程中，我相信，您会被问到是否要删除/var/lib/mysql中的数据库。我说不行，但我做了备份以防万一。然后，我改变了配置，使之与原来问题中的配置相同，而且它起了作用。

Answer 3

通过为配置文件设置适当的用户权限，解决了同样的问题：

chmod 644 /etc/mysql/mysql.cnf

Mysql没有读取配置，而它有755，我使用这个线程的答案找到了这个配置。