fix for bug #16413 (Events: statements don't appear in the general query log)

WL#1034


mysql-test/t/events_logs_tests-master.opt:
  Rename: mysql-test/t/events_slow_query-master.opt -> mysql-test/t/events_logs_tests-master.opt
sql/event_timed.cc:
  ask the anonymous SP to log general statements
sql/sp_head.cc:
  save the OPTION_LOG_OFF and restore it after execution
sql/sp_head.h:
  add a new flag for general log
mysql-test/r/events_logs_tests.result:
  update result file
mysql-test/t/events_logs_tests.test:
  add test for general log

mysql-test/r/events_slow_query.result → mysql-test/r/events_logs_tests.result

 create database if not exists events_test;
 use events_test;
+"Check General Query Log"
+SET GLOBAL event_scheduler=0;
+create event log_general on schedule every 1 minute do seLect 'alabala', sleep(3) from dual;
+TRUNCATE mysql.general_log;
+SELECT user_host, command_type, argument FROM mysql.general_log;
+user_host	command_type	argument
+root[root] @ localhost []	Query	SELECT user_host, command_type, argument FROM mysql.general_log
+SET GLOBAL event_scheduler=1;
+"Wait the scheduler to start"
+"Should see 3 rows. The create, the seLect and the select from the general_log"
+SELECT user_host, command_type, argument FROM mysql.general_log;
+user_host	command_type	argument
+root[root] @ localhost []	Query	SELECT user_host, command_type, argument FROM mysql.general_log
+root[root] @ localhost []	Query	SET GLOBAL event_scheduler=1
+root[root] @ localhost [localhost]	Query	seLect 'alabala', sleep(3) from dual
+root[root] @ localhost []	Query	SELECT user_host, command_type, argument FROM mysql.general_log
+DROP EVENT log_general;
+SET GLOBAL event_scheduler=0;
+"Check slow query log"
 "Save the values"
 SET @old_global_long_query_time:=(select get_value());
 SET @old_session_long_query_time:=@@long_query_time;

mysql-test/t/events_slow_query.test → mysql-test/t/events_logs_tests.test

 create database if not exists events_test;
 use events_test;
 
+--echo "Check General Query Log"
+SET GLOBAL event_scheduler=0;
+create event log_general on schedule every 1 minute do seLect 'alabala', sleep(3) from dual;
+TRUNCATE mysql.general_log;
+SELECT user_host, command_type, argument FROM mysql.general_log;
+SET GLOBAL event_scheduler=1;
+--echo "Wait the scheduler to start"
+--echo "Should see 3 rows. The create, the seLect and the select from the general_log"
+--sleep 2
+SELECT user_host, command_type, argument FROM mysql.general_log;
+DROP EVENT log_general;
+SET GLOBAL event_scheduler=0;
+--sleep 1
+
+--echo "Check slow query log"
 --disable_query_log
 DELIMITER |;
 CREATE FUNCTION get_value()

sql/event_timed.cc

@@ -1164,6 +1164,8 @@ Event_timed::execute(THD *thd, MEM_ROOT *mem_root)
     empty_item_list.empty();
     if (thd->enable_slow_log)
       sphead->m_flags|= sp_head::LOG_SLOW_STATEMENTS;
+    sphead->m_flags|= sp_head::LOG_GENERAL_LOG;
+
     ret= sphead->execute_procedure(thd, &empty_item_list);
   }
   else

sql/sp_head.cc

@@ -1413,6 +1413,7 @@ sp_head::execute_procedure(THD *thd, List<Item> *args)
   sp_rcontext *save_spcont, *octx;
   sp_rcontext *nctx = NULL;
   bool save_enable_slow_log= false;
+  bool save_log_general= false;
   DBUG_ENTER("sp_head::execute_procedure");
   DBUG_PRINT("info", ("procedure %s", m_name.str));
 
@@ -1511,20 +1512,28 @@ sp_head::execute_procedure(THD *thd, List<Item> *args)
 
     DBUG_PRINT("info",(" %.*s: eval args done", m_name.length, m_name.str));
   }
-  if (thd->enable_slow_log && !(m_flags & LOG_SLOW_STATEMENTS))
+  if (!(m_flags & LOG_SLOW_STATEMENTS) && thd->enable_slow_log)
   {
     DBUG_PRINT("info", ("Disabling slow log for the execution"));
-    save_enable_slow_log= thd->enable_slow_log;
+    save_enable_slow_log= true;
     thd->enable_slow_log= FALSE;
   }
+  if (!(m_flags & LOG_GENERAL_LOG) && !(thd->options & OPTION_LOG_OFF))
+  {
+    DBUG_PRINT("info", ("Disabling general log for the execution"));
+    save_log_general= true;
+    /* disable this bit */
+    thd->options |= OPTION_LOG_OFF;
+  }
   thd->spcont= nctx;
   
   if (!err_status)
     err_status= execute(thd);
 
-  if (save_enable_slow_log && !(m_flags & LOG_SLOW_STATEMENTS))
-    thd->enable_slow_log= save_enable_slow_log;
-
+  if (save_log_general)
+    thd->options &= ~OPTION_LOG_OFF;
+  if (save_enable_slow_log)
+    thd->enable_slow_log= true;
   /*
     In the case when we weren't able to employ reuse mechanism for
     OUT/INOUT paranmeters, we should reallocate memory. This
@@ -2303,6 +2312,9 @@ sp_instr_stmt::execute(THD *thd, uint *nextp)
       (the order of query cache and subst_spvars calls is irrelevant because
       queries with SP vars can't be cached)
     */
+    if (unlikely((thd->options & OPTION_LOG_OFF)==0))
+      general_log_print(thd, COM_QUERY, "%s", thd->query);
+
     if (query_cache_send_result_to_client(thd,
 					  thd->query, thd->query_length) <= 0)
     {

sql/sp_head.h

@@ -125,7 +125,8 @@ public:
     HAS_SET_AUTOCOMMIT_STMT= 64,// Is set if a procedure with 'set autocommit'
     /* Is set if a procedure with COMMIT (implicit or explicit) | ROLLBACK */
     HAS_COMMIT_OR_ROLLBACK= 128,
-    LOG_SLOW_STATEMENTS= 256
+    LOG_SLOW_STATEMENTS= 256,   // Used by events
+    LOG_GENERAL_LOG= 512        // Used by events
   };
 
   /* TYPE_ENUM_FUNCTION, TYPE_ENUM_PROCEDURE or TYPE_ENUM_TRIGGER */