Bug #81897 Can't connect to MySQL by using Workbench after configure MySQL Enterprise Audit
Submitted: 17 Jun 2016 4:33 Modified: 29 Jul 2016 23:19
Reporter: Shinya Sugiyama Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Security: Audit Severity:S3 (Non-critical)
Version:5.7.13 OS:Any
Assigned to: CPU Architecture:Any
Tags: MySQL Enterprise Audit, workbench

[17 Jun 2016 4:33] Shinya Sugiyama
Description:
If I configure MySQL Enterprise Audit filtering configuration, I can't connect to the MySQL Server via MySQL Workbench.

[root@misc01 admin]# mysql -u root -p -e "select @@version";
Enter password: 
+-------------------------------------------+
| @@version                                 |
+-------------------------------------------+
| 5.7.13-enterprise-commercial-advanced-log |
+-------------------------------------------+
[root@misc01 admin]# 

Filter Description
https://dev.mysql.com/doc/refman/5.7/en/audit-log-installation.html

【 Installation Flow】

https://dev.mysql.com/doc/refman/5.7/en/audit-log-installation.html

shell> mysql -u root -p < audit_log_filter_linux_install.sql
Enter password: (enter root password here)

How to repeat:
I install MySQL Enterprise Audit with

root@localhost [mysql]> SELECT audit_log_filter_set_filter('log_confidential', '{ "filter": { "class": { "name": "table_access","event": { "name": "read","log": { "field": { "name": "table_name.str","value": "confidential" } } } } } }');
+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| audit_log_filter_set_filter('log_confidential', '{ "filter": { "class": { "name": "table_access","event": { "name": "read","log": { "field": { "name": "table_name.str","value": "confidential" } } } } } }') |
+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| OK                                                                                                                                                                                                              |
+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.01 sec)

audit_target@localhost [mysql]> 

root@localhost [mysql]> CREATE USER confidential@'%';
Query OK, 0 rows affected (0.00 sec)

root@localhost [mysql]> alter user confidential@'%' identified by 'password';
Query OK, 0 rows affected (0.00 sec)

root@localhost [mysql]> GRANT ALL ON *.* TO 'confidential'@'%';
Query OK, 0 rows affected (0.00 sec)

root@localhost [mysql]> SELECT audit_log_filter_set_user('confidential@%','log_confidential');
+----------------------------------------------------------------+
| audit_log_filter_set_user('confidential@%','log_confidential') |
+----------------------------------------------------------------+
| OK                                                             |
+----------------------------------------------------------------+
1 row in set (0.00 sec)

root@localhost [mysql]> select * from audit_log_filter;
+------------------+---------------------------------------------------------------------------------------------------------------------------------------------------+
| NAME             | FILTER                                                                                                                                            |
+------------------+---------------------------------------------------------------------------------------------------------------------------------------------------+
| log_confidential | {"filter": {"class": {"name": "table_access", "event": {"log": {"field": {"name": "table_name.str", "value": "confidential"}}, "name": "read"}}}} |
+------------------+---------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.23 sec)

root@localhost [mysql]>  select * from audit_log_user;
+--------------+------+------------------+
| USER         | HOST | FILTERNAME       |
+--------------+------+------------------+
| confidential | %    | log_confidential |
+--------------+------+------------------+
1 row in set (0.00 sec)

root@localhost [mysql]> 

■ I can't connect to the MySQL by using workbench after above configuration.

■ Once I delete configuration. I can connect to the MySQL by using workbench.

【 DELETE Audit Configuration 】

root@localhost [mysql]> DELETE FROM audit_log_filter;DELETE FROM audit_log_user;

Query OK, 1 row affected (0.20 sec)

Query OK, 1 row affected (0.00 sec)

root@localhost [mysql]> SELECT audit_log_filter_flush() AS 'Result';
+--------+
| Result |
+--------+
| OK     |
+--------+
1 row in set (0.00 sec)

root@localhost [mysql]> 

Suggested fix:
Please check authentication flow before and after configure audit filtering rules.

Best Regard
Shinya
[17 Jun 2016 4:34] Shinya Sugiyama
Workbech Error Message after configure audit json filter

Attachment: error_from_workbench.PNG (image/png, text), 46.32 KiB.

[17 Jun 2016 4:35] Shinya Sugiyama
Workbech is 6.3.6 (64bit)

Regard
Shinya
[20 Jun 2016 12:44] Marek Szymczak
2016-06-20T21:25:09.022645+09:00 5 [Warning] IP address '192.168.56.1' could not be resolved: Name or service not known
12:25:09 UTC - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=2
max_threads=151
thread_count=3
connection_count=2
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338781 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7faed400a060
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7faedc26bea8 thread_stack 0x40000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x35)[0xf30175]
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x4a4)[0x7ae894]
/lib64/libpthread.so.0(+0xf130)[0x7faf006e2130]
/lib64/libc.so.6(+0x1627d1)[0x7faeff40f7d1]
/usr/local/mysql/lib/plugin/audit_log.so(_ZN24Audit_log_filter_handler6handleEP3THD19mysql_event_class_tPKv+0x15f)[0x7faeeb09eaef]
/usr/local/mysql/lib/plugin/audit_log.so(+0x19a66)[0x7faeeb082a66]
/usr/local/mysql/bin/mysqld[0x7af86b]
/usr/local/mysql/bin/mysqld(_Z18mysql_audit_notifyP3THD33mysql_event_connection_subclass_tPKci+0x1f2)[0x7b0582]
/usr/local/mysql/bin/mysqld[0xccc68c]
/usr/local/mysql/bin/mysqld(_Z22thd_prepare_connectionP3THD+0x5e)[0xcccade]
/usr/local/mysql/bin/mysqld(handle_connection+0x279)[0xdd8a29]
/usr/local/mysql/bin/mysqld(pfs_spawn_thread+0x174)[0x11e4704]
/lib64/libpthread.so.0(+0x7df3)[0x7faf006dadf3]
/lib64/libc.so.6(clone+0x6d)[0x7faeff3a31ad]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0): is an invalid pointer
Connection ID (thread ID): 5
Status: NOT_KILLED
[20 Jun 2016 12:52] Marek Szymczak
Possibly it's a duplicate of Bug#23523231. Shinya will check, whether this can be reprodced in 5.7.14.
[22 Jul 2016 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[29 Jul 2016 23:19] Shinya Sugiyama
I just finished to upgrade the instance to MySQL5.7.14.
Then I finished to confirm everything is working fine now.
There is no error log even I connect from workbench. (Successfully connected)

I seems authentication is working fine now. 

audit_target@192.168.56.113 [(none)]> select @@version;
+-------------------------------------------+
| @@version                                 |
+-------------------------------------------+
| 5.7.14-enterprise-commercial-advanced-log |
+-------------------------------------------+
1 row in set (0.00 sec)

audit_target@192.168.56.113 [(none)]> select user(),current_user();select * from mysql.audit_log_user;
+---------------------+----------------+
| user()              | current_user() |
+---------------------+----------------+
| audit_target@misc02 | audit_target@% |
+---------------------+----------------+
1 row in set (0.00 sec)

+--------------+------+------------+
| USER         | HOST | FILTERNAME |
+--------------+------+------------+
| audit_target | %    | log_all    |
+--------------+------+------------+
1 row in set (0.01 sec)

audit_target@192.168.56.113 [(none)]> 

Thank you for fix it.
Shinya