MySQL Bugs: #82118: MYSQL_AUDIT_GENERAL_LOG event does not report database to audit plugins in 5.7

Bug #82118	MYSQL_AUDIT_GENERAL_LOG event does not report database to audit plugins in 5.7
Submitted:	5 Jul 2016 17:26	Modified:	6 Jul 2016 14:24
Reporter:	Sergei Glushchenko (OCA)	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Security: Audit	Severity:	S3 (Non-critical)
Version:	5.7.13	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
Lets take a look at how audit plugins get notified about mysql_change_db ('use db' in mysql cli).

5.6:

in dispatch_command function:

  case COM_INIT_DB:
  {
    LEX_STRING tmp;
    status_var_increment(thd->status_var.com_stat[SQLCOM_CHANGE_DB]);
    thd->convert_string(&tmp, system_charset_info,
      packet, packet_length, thd->charset());
    if (!mysql_change_db(thd, &tmp, FALSE))
    {
      general_log_write(thd, command, thd->db, thd->db_length);
      my_ok(thd);
    }
    break;
  }

Note that thd->db is the 'query' value for general_log_write. It then passed all the way down to mysql_audit_general_log which takes query_str and query_len parameters and using it instead of query stored in THD.

5.7:

  case COM_INIT_DB:
  {
    LEX_STRING tmp;
    thd->status_var.com_stat[SQLCOM_CHANGE_DB]++;
    thd->convert_string(&tmp, system_charset_info,
                        com_data->com_init_db.db_name,
                        com_data->com_init_db.length, thd->charset());

    LEX_CSTRING tmp_cstr= {tmp.str, tmp.length};
    if (!mysql_change_db(thd, tmp_cstr, FALSE))
    {
      query_logger.general_log_write(thd, command,
                                     thd->db().str, thd->db().length);
      my_ok(thd);
    }
    break;
  }

Looks OK so far, DB passed as 'query' value. But then general_log_write invokes mysql_audit_general_log which doesn't take query as an argument, so it is lost now and query will simply be NULL.

How to repeat:
Read the code. Also you should probably see it in enterprise audit plugin output.

Suggested fix:
Restore 5.6 behaviour.

I am unable to spot a problem. The called function gets `command` as its parameters. And it deals with it twice, both times properly, IMHO:

1)

#ifndef EMBEDDED_LIBRARY
  /* Send a general log message to the audit API. */
  mysql_audit_general_log(thd, command_name[(uint) command].str,
                          command_name[(uint) command].length);
#endif

2)

 for (Log_event_handler **current_handler= general_log_handler_list;
       *current_handler; )
  {
    error|= (*current_handler++)->log_general(thd, current_utime, user_host_buff,
                                              user_host_len, thd->thread_id(),
                                              command_name[(uint) command].str,
                                              command_name[(uint) command].length,
                                              query, query_length,
                                              thd->variables.character_set_client);
  }

Yes. Command is handled properly. It is "Init DB". What I am looking for is `query`.

Here is the mysql_audit_general_log from 5.6:

static inline
void mysql_audit_general_log(THD *thd, const char *cmd, uint cmdlen,
                             const char *query_str, size_t query_len)

and from 5.7:

inline static
int mysql_audit_general_log(THD *thd, const char *cmd, size_t cmdlen)

Eventually, notify function of the audit plugin will receive command="Init DB" and query="database_name" in 5.6, but in 5.7 command="Init DB" and query="".

Hi!

Your last response cleared out a matter.

Verified as reported.

Thank you very much !!!