Bug #79079 Infinite recursion by calling my_message from MYSQL_AUDIT_GENERAL_CLASS handler
Submitted: 2 Nov 2015 15:59 Modified: 24 Feb 2016 23:16
Reporter: Laurynas Biveinis (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Security: Audit Severity:S2 (Serious)
Version:5.7.9 OS:Any
Assigned to: CPU Architecture:Any
Tags: plugin api

[2 Nov 2015 15:59] Laurynas Biveinis
Description:
MYSQL_AUDIT_GENERAL_CLASS handler calling my_message will call my_message_sql, which will call mysql_audit_general(MYSQL_AUDIT_GENERAL_ERROR), which will notify plugins with a MYSQL_AUDIT_GENERAL_CLASS event, which will...

* thread #24: tid = 0x0017, 0x000000010ecbb574 mysqld`mysql_audit_notify(thd=0x00007fd9fc91dc00, subclass=MYSQL_AUDIT_GENERAL_ERROR, error_code=3164, msg="Aborting an unabortable event", msg_len=29) + 20 at sql_audit.cc:226, stop reason = signal SIGSTOP
    frame #0: 0x000000010ecbb574 mysqld`mysql_audit_notify(thd=0x00007fd9fc91dc00, subclass=MYSQL_AUDIT_GENERAL_ERROR, error_code=3164, msg="Aborting an unabortable event", msg_len=29) + 20 at sql_audit.cc:226
    frame #1: 0x000000010ecae8b7 mysqld`::my_message_sql(uint, const char *, myf) [inlined] mysql_audit_general(event_subtype=MYSQL_AUDIT_GENERAL_ERROR) + 87 at sql_audit.h:92
    frame #2: 0x000000010ecae894 mysqld`::my_message_sql(error=1105, str="Aborting an unabortable event", MyFlags=0) + 52 at mysqld.cc:2209
    frame #3: 0x0000000116339ce8 adt_null.so`audit_null_notify(thd=0x00007fd9fc91dc00, event_class=MYSQL_AUDIT_GENERAL_CLASS, event=0x0000700000b049a8) + 728 at audit_null.c:387
    frame #4: 0x000000010ecbb884 mysqld`mysql_audit_notify(THD*, mysql_event_general_subclass_t, int, char const*, unsigned long) [inlined] plugins_dispatch(thd=<unavailable>, plugin=<unavailable>) + 804 at sql_audit.cc:1036
    frame #5: 0x000000010ecbb863 mysqld`mysql_audit_notify(THD*, mysql_event_general_subclass_t, int, char const*, unsigned long) + 82 at sql_audit.cc:1077
  * frame #6: 0x000000010ecbb811 mysqld`mysql_audit_notify(thd=0x00007fd9fc91dc00, subclass=<unavailable>, error_code=3164, msg=<unavailable>, msg_len=<unavailable>) + 689 at sql_audit.cc:273
    frame #7: 0x000000010ecae8b7 mysqld`::my_message_sql(uint, const char *, myf) [inlined] mysql_audit_general(event_subtype=MYSQL_AUDIT_GENERAL_ERROR) + 87 at sql_audit.h:92
    frame #8: 0x000000010ecae894 mysqld`::my_message_sql(error=1105, str="Aborting an unabortable event", MyFlags=0) + 52 at mysqld.cc:2209
    frame #9: 0x0000000116339ce8 adt_null.so`audit_null_notify(thd=0x00007fd9fc91dc00, event_class=MYSQL_AUDIT_GENERAL_CLASS, event=0x0000700000b055a8) + 728 at audit_null.c:387
    frame #10: 0x000000010ecbb884 mysqld`mysql_audit_notify(THD*, mysql_event_general_subclass_t, int, char const*, unsigned long) [inlined] plugins_dispatch(thd=<unavailable>, plugin=<unavailable>) + 804 at sql_audit.cc:1036
    frame #11: 0x000000010ecbb863 mysqld`mysql_audit_notify(THD*, mysql_event_general_subclass_t, int, char const*, unsigned long) + 82 at sql_audit.cc:1077
    frame #12: 0x000000010ecbb811 mysqld`mysql_audit_notify(thd=0x00007fd9fc91dc00, subclass=<unavailable>, error_code=3164, msg=<unavailable>, msg_len=<unavailable>) + 689 at sql_audit.cc:273
    frame #13: 0x000000010ecae8b7 mysqld`::my_message_sql(uint, const char *, myf) [inlined] mysql_audit_general(event_subtype=MYSQL_AUDIT_GENERAL_ERROR) + 87 at sql_audit.h:92

How to repeat:
Apply this

--- ./plugin/audit_null/audit_null.c	2015-11-02 17:57:51.000000000 +0200
+++ ../mysql-5.7.9/plugin/audit_null/audit_null.c	2015-11-02 17:45:21.000000000 +0200
@@ -384,6 +384,7 @@
   {
     const struct mysql_event_general *event_general=
                                     (const struct mysql_event_general *)event;
+    my_message(ER_AUDIT_API_ABORT, "Aborting an unabortable event", MYF(0));
 
     switch (event_general->event_subclass)
     {

Then run i.e. audit_plugin_2 testcase.

Suggested fix:
Document and enforce that MYSQL_AUDIT_GENERAL_CLASS is non-terminatable event?
[2 Nov 2015 16:04] Laurynas Biveinis
The infinite recursion happens with both debug and release builds, but I wouldn't consider this to be a security issue as server access to install the plugin is required anyway.
[2 Nov 2015 16:53] MySQL Verification Team
Verified as reported !!!!
[3 Nov 2015 9:03] Laurynas Biveinis
If my_message is called for a different event subclass than MYSQL_AUDIT_GENERAL_ERROR, it crashes a debug build in a different way: bug 79090.
[26 Nov 2015 15:01] Georgi Kodinov
Laurynas,

I'm trying to understand what do you expect from the server to do. 
If you trigger an event from a handler that processes an event it would be most natural to expect the event to happen again IMHO.
Or do you expect the server to turn off event logging for each handler ?
[27 Nov 2015 5:17] Laurynas Biveinis
I don't have a plugin that depends on this. But I can imagine plugin developers getting burned here by, say, trying to do some work in the event handler that might fail (memory allocation, file I/O, whatever), and if that work fails, duly reporting the failure, inadvertently causing infinite recursion. If I'm not mistaken, the only workaround here is fprintf(stderr), resulting in non-standard format diagnostics? Or is it possible to do a non-aborting my_message() ?

Thus I think ideally I'd prefer my_message called from plugins not resulting in further (nested) notifications or at least a doc note how to issue diagnostics from plugin if it is handling MYSQL_AUDIT_GENERAL_ERROR.
[30 Nov 2015 16:28] Georgi Kodinov
Thanks, Laurynas !

I understand that this is a bit of unexpected. 

But this being the audit API (supposed to reliably capture all events and supporting multiple simultaneously active plugins per event etc) I'd be reluctant to do as the signal handling does in C and turn off the audit notifications generated by the handler itself inside the server.

I will think a bit more on a better solution and will mark the bug as a documentation one if nothing intelligent comes as a result.
[24 Feb 2016 23:16] Paul Dubois
Noted in 5.7.12, 5.8.0 changelog.

Calling my_message() from the MYSQL_AUDIT_GENERAL_CLASS handler
resulted in infinite recursion.
[31 Mar 2016 5:21] Erlend Dahl
Bug#79090 my_message in MYSQL_AUDIT_GENERAL_CLASS handler crashes debug build

was marked as a duplicate.