Percona Server moved to https://jira.percona.com/projects/PS

Merge lp:~dingqi-lxb/percona-server/5.5_log_queries_in_memory into lp:percona-server/5.5

  1. 5.5_log_queries_in_memory
  2. Merge into 5.5
Proposed by 林晓斌 on 2012-01-02
Status: Work in progress
Proposed branch: lp:~dingqi-lxb/percona-server/5.5_log_queries_in_memory
Merge into: lp:percona-server/5.5
Diff against target: 896 lines (+879/-0)
3 files modified
doc/source/diagnostics/slow_log_in_memory.rst (+74/-0)
patches/series (+1/-0)
patches/slowlog_in_memory.patch (+804/-0)
To merge this branch: bzr merge lp:~dingqi-lxb/percona-server/5.5_log_queries_in_memory
Reviewer Review Type Date Requested Status
Oleg Tsarev (community) 2012-01-02 Needs Fixing on 2012-01-11
Review via email: mp+87244@code.launchpad.net

This proposal supersedes a proposal from 2011-12-29.

Description of the change

http://jenkins.percona.com/view/Percona%20Server%205.5/job/percona-server-5.5-param/258/

patch for https://blueprints.launchpad.net/percona-server/+spec/log-queries-in-memory.

add a variable 'slowlog_in_memory_audit_max_memory' and global status 'slow_log_current_memory'

If the current_memory grows larger than max_memory, the eldest ones will be wash out.
Same action happens when max_mamory are set to a new value that is less than current_memory.

To post a comment you must log in.
Oleg Tsarev (tsarev) wrote : Posted in a previous version of this proposal

1. Please add patch name to the "patches/series" file
2. About innodb_trx_id. Please look to two following cases:
 * log_slow_verbosity doesn't set "innodb"
 * query doesn't use the InnoDB
In first case slow query log will has no information about InnoDB
In second case slow query will have line "# No InnoDB statistics available for this query\n"
In this two cases innodb_trx_id will be incorrect, and you can't use and setup it.

Please handle variable innodb_was_used correctly (at least for innodb_trx_id)

3. Following is very, very bad:
+ if (general_query)
+ {
....
+ }
+ else
+ {
+ this->general_query= "NULL";
+ this->general_query_len= 5;
+ }
You are break SQL semantic. For example query:
SELECT * FROM INSFORMATION_SCHEMA.I_S_SLOW_LOG WHERE QUERY IS NULL
or any join will not work correctly.
You are break SQL language semantic by string "NULL" instead of NULL

Same for Schema.

4. I_S_SLOW_LOG not very good name. Why SLOW_LOG bad?

5. Please add documentation to the doc/

6. Sleep in the test file - bad idea. Please replace this by debug variable query_exec_time.

7. Please add tests to sys_vars suite for the all added variables.

Please fix this, and I will review again.

review: Needs Fixing
Oleg Tsarev (tsarev) wrote : Posted in a previous version of this proposal

8.
+ ulonglong utime_of_query= thd->current_utime() - thd->utime_after_lock;
+ if (utime_of_query <= thd->variables.long_query_time)
+ return;

Please look into the slow_extended.patch:

static inline ulonglong get_query_exec_time(THD *thd, ulonglong cur_utime)
...
thd->server_status|= SERVER_QUERY_WAS_SLOW;

Please better use this status variable, instead of calculate query execution time directly.

林晓斌 (dingqi-lxb) wrote : Posted in a previous version of this proposal

Thank you. Oleg, I have some items to discuss.

2. About innodb_trx_id. Please look to two following cases
   In these two cases, the variable thd->innodb_trx_id is set to 0. It seems that I have to show it in the result table as 0, is there other result even use innodb_was_used ?

8.About calculating query execution time directly, it is because that I have to get the query_time, the status is not enough.

* Why plugin doesn't uninstall in test?
  You mean that it shows " Plugin is busy and will be uninstalled on shutdown" in result-file? It is the same with the demo for audit plugin "null_audit", the strategy decided by mysqld

Oleg Tsarev (tsarev) wrote : Posted in a previous version of this proposal

On Mon, Dec 12, 2011 at 12:05 PM, 林晓斌 <email address hidden> wrote:
> Thank you. Oleg, I have some items to discuss.
>
> 2. About innodb_trx_id. Please look to two following cases
>   In these two cases, the variable thd->innodb_trx_id is set to 0.  It seems that I have to show it in the result table as 0, is there other result even use innodb_was_used ?

I think right decision is "NULL" value instead of 0.
>
> 8.About calculating query execution time directly, it is because that I have to get the query_time, the status is not enough.
>
> * Why plugin doesn't uninstall in test?
>  You mean that it shows " Plugin is busy and will be uninstalled on shutdown" in result-file? It is the same with the demo for audit plugin "null_audit", the strategy decided by mysqld

Ok

> --
> https://code.launchpad.net/~dingqi-lxb/percona-server/5.5_log_queries_in_memory/+merge/85251
> You are reviewing the proposed merge of lp:~dingqi-lxb/percona-server/5.5_log_queries_in_memory into lp:percona-server.

--
Oleg Tsarev, Software Engineer, Percona Inc.

林晓斌 (dingqi-lxb) wrote : Posted in a previous version of this proposal

2. About innodb_trx_id. Generally, when the thd->innodb_trx_id is 0, the value of "INNODB_TRX_ID" should show NULL, so the thd->innodb_was_used will not be imported here.

7. Please add tests to sys_vars suite for the all added variables.
   The variable add in this plugin will not be seen in other test-case, it can only be seen the plugin is installed. So, is test-case in sys_vars suits necessary?

Stewart Smith (stewart) wrote : Posted in a previous version of this proposal

On Wed, 21 Dec 2011 02:50:35 -0000, 林晓斌 <email address hidden> wrote:
> +There are two plugins in the feature. They can be installed by
> command ``"install plugin SLOWLOG_IN_MEMORY_AUDIT soname
> 'slowlog_in_memory.so'"`` and ``"install plugin SLOW_LOG soname
> 'slowlog_in_memory.so'"``, they work by keeping one list in memory.

I think we should be consistent in naming. SLOW_LOG instead of SLOWLOG
and slow_log instead of slowlog.
--
Stewart Smith

Baron Schwartz (baron-xaprb) wrote : Posted in a previous version of this proposal

I'm sorry that I haven't noticed this discussion before, but I believe that it would be best to avoid a query time in milliseconds:

1. It should have microsecond resolution. Milliseconds is not enough.
2. It should be named EXEC_TIME and should be a floating-point value in seconds so the user does not have to convert the value to seconds.

Oleg Tsarev (tsarev) wrote :

About documentation:

1) Please link to page page "Slow Log In Memory" to the index of documentation (to "Diagnostic" article)

2) "MS_QUERY_TIME – The query_exec_time of the query, in second."
But looks like time in the milliseconds

About the patch:

3) You avoid the "quiltrc" config file from the root of branch. As result your patch has incorrect format.
Please, use "quilt --quiltrc=quiltrc ..." while you touch the patches

About the feature:
4) I think, we should add at least following:
  * User
  * Query_time (microseconds)

About the tests:

5) Here is little example of incorrect work (JUST EXAMPLE):
http://bazaar.launchpad.net/~tsarev/percona-server/5.5_log_queries_in_memory/revision/202
So, your implementation avoid all variables related to slow query log, except long_query_time.
  * How to right test: modify all tests provided by slow_extended.patch. Right now their check a slow query log by "log_grep.inc". You should add similar checks of plugin to every test.

About the implementation:

6) Incorrect works with query exec time:
 ulonglong utime_of_query= thd->current_utime() - thd->utime_after_lock;
 * Possible scenario: query doesn't pass to slow query log, but pass to INFORMATION_SCHEMA.SLOW_LOG memory. Or opposite.
 * How to fix: you shoud use thd->server_status variable for detect insert or don't insert event to SLOW_LOG table. This allows to support all related options from PS.
 * What requires the modify: slow_extended.patch. thd->server_status variable (SERVER_QUERY_WAS_SLOW flag) should setup status of every query (and also should be used both in PS and plugin)

7) Separatelly about this:

+ ulonglong utime_of_query= thd->current_utime() - thd->utime_after_lock;
+
+#ifndef DBUG_OFF
+ if (thd->variables.query_exec_time != 0)
+ utime_of_query= thd->lex->sql_command != SQLCOM_SET_OPTION ? thd->variables.query_exec_time : 0;
+#endif
+
+ if (utime_of_query <= thd->variables.long_query_time)
+ return;

Copy-paste - not a very good idea.

8) Class slow_log_list. Some methods lock/unlock mutexes, some not (pop_front). It think this is a bad contract-to-interface .

9) Event Id can be missordered (different from order of events in the list)

10) Order of event can be missordered (different from slow query log)

11) Class slow_log_list. Why "first" and "last" are public members?

12) Please also note: subunit has a #bug 911237 - according to 5.5 testing not a work right now. Please merge fix then it will be merged to lp:percona-server

review: Needs Fixing
Reply
Oleg Tsarev (tsarev) wrote :

To 12) - fix already in lp:percona-server, just need a merge before future tests

Reply
林晓斌 (dingqi-lxb) wrote :

4)There is Query_time already, will be shown as 1.1234, in senconds, what does this Query_time mean?

6) ok, before recored it, I will check thd->server_status before. But the result of utime_of_query has to be re-calculated here all the same.

7) what does this mean?

9) Yes, the procedure of assigning event_id and putting into the list is not locked as a whole, for performance consideration. Ok, I will lock them as a whole.

10) This can not be confirmed. Because the procedre of logging into slow log and loging into memory are different plugins. Is there any proposal?

11) Because the "first" and "last" needs to be accessed at i_s_fill_table_slow_log

Reply
Oleg Tsarev (tsarev) wrote :

4) This is Ok. Also please ask Baron about Lock_time
6) Not a "before", but "instead". You should not use direct utime_of_query calculation. Please replace any calculation by check of flag thd->server_status
7) This is mean you should not use copy-paste. Never.
9) Any perfomance consideration should not break the correct work
10) You can modify the slow_extended.patch and create event id on server-side. But this is requires consideration
11) Why you didn't add public interface for iteration instead of access to members?

Reply
林晓斌 (dingqi-lxb) wrote :

6) Check can use thd->server_status, but I need to calculate the utime_of_query if the thd->server_status & SERVER_QUERY_WAS_SLOW != 0, because I need to recored it, right?

10) It will make the plugin depart from the concept that it can be used in both Percona-server and Oracle-mysql directly. I propose that it remains the current strategy, if the misorder between memory and slow log can be tolerant.

Reply
Oleg Tsarev (tsarev) wrote :

6) right
10) ok

Reply

Unmerged revisions

200. By 林晓斌 on 2012-01-01

add slowlog_in_memory.patch

199. By 林晓斌 on 2012-01-01

merge from trunk

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
=== added file 'doc/source/diagnostics/slow_log_in_memory.rst'
--- doc/source/diagnostics/slow_log_in_memory.rst 1970-01-01 00:00:00 +0000
+++ doc/source/diagnostics/slow_log_in_memory.rst 2012-01-02 12:24:34 +0000
@@ -0,0 +1,74 @@
1.. _slow_log_in_memory:
2
3=================
4 Slow Log In Memory
5=================
6
7The feature is used to save slow queries in memory. This feature adds an ``INFORMATION_SCHEMA.SLOW_LOG`` table to show the latest queries, a variable to limit the max memory used, and status to show the status of memory used.
8
9There are two plugins in the feature. They can be installed by command ``"install plugin SLOWLOG_IN_MEMORY_AUDIT soname 'slowlog_in_memory.so'"`` and ``"install plugin SLOW_LOG soname 'slowlog_in_memory.so'"``, they work by keeping one list in memory.
10
11
12Other Information
13=================
14
15 * Author/Origin:
16 *Percona*; *Percona* added an ``INFORMATION_SCHEMA`` table and the :variable:`slowlog_in_memory_audit_max_memory` and the :status:`slow_log_current_memory`.
17
18System Variables
19================
20
21.. variable:: slowlog_in_memory_audit_max_memory
22
23 :cli: Yes
24 :conf: Yes
25 :scope: Global
26 :dyn: Yes
27 :vartype: ULONG
28 :default: 1M
29 :range: 0 - 1G
30
31The variable is used to limit the max-memory used for slow log. If a new slow query will make the `current_memory` bigger than this value, the most eldest items will be discarded, until there is enough memory for new item. When the value is decrease dynamically, it behaves the same.
32
33Status Variables
34================
35
36One new status variable was introduced by this feature.
37
38.. variable:: slow_log_current_memory
39
40 :vartype: ULONG
41 :scope: Global
42
43The variable showes the current memory used for the slow queries. It can never be bigger than the `slowlog_in_memory_audit_max_memory` variable.
44
45
46INFORMATION_SCHEMA Tables
47=========================
48
49.. table:: INFORMATION_SCHEMA.SLOW_LOG
50
51 :column EVENT_ID: A global increment id for every record in the table, can be used to identify every one.
52 :column TIMESTAMP: The timestamp when the query stop.
53 :column THREAD_ID: The thread_id of the query.
54 :column DB: The current database() of the query, may be NULL.
55 :column INNODB_TRX_ID: The Innodb_trx_id if InnoDB is used, may be NULL.
56 :column ERROR: The errno of the query, 0 means no error.
57 :column MS_QUERY_TIME: The query_exec_time of the query, in second.
58 :column QUERY: The query statement.
59
60This table holds the lastest slow queries.
61
62Example: ::
63
64 mysql> select * from information_schema.slow_log \G
65 *************************** 1. row ***************************
66 EVENT_ID: 1
67 TIMESTAMP: 1323753896
68 THREAD_ID: 2
69 DB: test
70 INNODB_TRX_ID: NULL
71 ERRNO: 0
72 MS_QUERY_TIME: 3001
73 QUERY: select sleep(3)
74
075
=== modified file 'patches/series'
--- patches/series 2011-12-16 09:37:26 +0000
+++ patches/series 2012-01-02 12:24:34 +0000
@@ -62,3 +62,4 @@
62bug45702.patch62bug45702.patch
63group_commit.patch63group_commit.patch
64warning_fixes.patch64warning_fixes.patch
65slowlog_in_memory.patch
6566
=== added file 'patches/slowlog_in_memory.patch'
--- patches/slowlog_in_memory.patch 1970-01-01 00:00:00 +0000
+++ patches/slowlog_in_memory.patch 2012-01-02 12:24:34 +0000
@@ -0,0 +1,804 @@
1--- a/plugin/slowlog_in_memory/CMakeLists.txt 1970-01-01 08:00:00.000000000 +0800
2+++ b/plugin/slowlog_in_memory/CMakeLists.txt 2011-12-22 21:08:28.000000000 +0800
3@@ -0,0 +1,17 @@
4+# Copyright (c) 2006, 2010, Oracle and/or its affiliates. All rights reserved.
5+#
6+# This program is free software; you can redistribute it and/or modify
7+# it under the terms of the GNU General Public License as published by
8+# the Free Software Foundation; version 2 of the License.
9+#
10+# This program is distributed in the hope that it will be useful,
11+# but WITHOUT ANY WARRANTY; without even the implied warranty of
12+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
13+# GNU General Public License for more details.
14+#
15+# You should have received a copy of the GNU General Public License
16+# along with this program; if not, write to the Free Software
17+# Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA
18+
19+MYSQL_ADD_PLUGIN(slowlog_in_memory slowlog_in_memory.cc
20+ MODULE_ONLY MODULE_OUTPUT_NAME "slowlog_in_memory")
21--- a/plugin/slowlog_in_memory/slowlog_in_memory.cc 1970-01-01 08:00:00.000000000 +0800
22+++ b/plugin/slowlog_in_memory/slowlog_in_memory.cc 2011-12-22 21:09:34.000000000 +0800
23@@ -0,0 +1,295 @@
24+/* Copyright (c) 2006, 2011, Oracle and/or its affiliates. All rights reserved.
25+
26+ This program is free software; you can redistribute it and/or
27+ modify it under the terms of the GNU General Public License
28+ as published by the Free Software Foundation; version 2 of
29+ the License.
30+
31+ This program is distributed in the hope that it will be useful,
32+ but WITHOUT ANY WARRANTY; without even the implied warranty of
33+ MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
34+ GNU General Public License for more details.
35+
36+ You should have received a copy of the GNU General Public License
37+ along with this program; if not, write to the Free Software
38+ Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA */
39+
40+#include "ut_slow_log_list.h"
41+
42+#if !defined(__attribute__) && (defined(__cplusplus) || !defined(__GNUC__) || __GNUC__ == 2 && __GNUC_MINOR__ < 8)
43+#define __attribute__(A)
44+#endif
45+typedef struct st_mysql_sys_var SYS_VAR;
46+uint max_memory_for_slow_log;
47+
48+/* lock management */
49+
50+slow_log_list *global_slow_log_list= NULL;
51+
52+/*
53+ Initialize the plugin at server start or plugin installation.
54+
55+ SYNOPSIS
56+ slow_log_in_memory_plugin_init()
57+
58+ DESCRIPTION
59+ Does nothing.
60+
61+ RETURN VALUE
62+ 0 success
63+ 1 failure (cannot happen)
64+*/
65+
66+static int slow_log_in_memory_plugin_init(void *arg __attribute__((unused)))
67+{
68+#ifdef HAVE_PSI_INTERFACE
69+ init_semisync_psi_keys();
70+#endif
71+
72+ mysql_mutex_init(key_ss_mutex_LOCK_slow_event_id_,
73+ &LOCK_slow_event_id_, MY_MUTEX_INIT_FAST);
74+ global_slow_log_list= new slow_log_list(max_memory_for_slow_log);
75+
76+ return 0;
77+}
78+
79+
80+/*
81+ Terminate the plugin at server shutdown or plugin deinstallation.
82+
83+ SYNOPSIS
84+ slow_log_in_memory_plugin_deinit()
85+ Does nothing.
86+
87+ RETURN VALUE
88+ 0 success
89+ 1 failure (cannot happen)
90+*/
91+
92+static int slow_log_in_memory_plugin_deinit(void *arg __attribute__((unused)))
93+{
94+ if (global_slow_log_list)
95+ {
96+ delete global_slow_log_list;
97+ global_slow_log_list= NULL;
98+ }
99+
100+ mysql_mutex_destroy(&LOCK_slow_event_id_);
101+ return 0;
102+}
103+
104+/*
105+ Foo
106+
107+ SYNOPSIS
108+ slow_log_in_memory_notify()
109+ thd connection context
110+
111+ DESCRIPTION
112+*/
113+
114+static void slow_log_in_memory_notify(MYSQL_THD thd __attribute__((unused)),
115+ unsigned int event_class,
116+ const void *event)
117+{
118+ if (max_memory_for_slow_log == 0) return;
119+
120+ if (event_class == MYSQL_AUDIT_GENERAL_CLASS)
121+ {
122+ const struct mysql_event_general *event_general=
123+ (const struct mysql_event_general *) event;
124+ if (event_general->event_subclass != MYSQL_AUDIT_GENERAL_STATUS)
125+ return;
126+
127+ ulonglong utime_of_query= thd->current_utime() - thd->utime_after_lock;
128+
129+#ifndef DBUG_OFF
130+ if (thd->variables.query_exec_time != 0)
131+ utime_of_query= thd->lex->sql_command != SQLCOM_SET_OPTION ? thd->variables.query_exec_time : 0;
132+#endif
133+
134+ if (utime_of_query <= thd->variables.long_query_time)
135+ return;
136+
137+ slow_log_t *tmp= new slow_log_t(event_general->general_time, event_general->general_thread_id, thd->db, thd->innodb_trx_id, event_general->general_error_code, (double)utime_of_query/1000000, event_general->general_query);
138+ global_slow_log_list->push_back(tmp);
139+ }
140+}
141+
142+
143+/*
144+ Plugin type-specific descriptor
145+*/
146+
147+static struct st_mysql_audit slow_log_in_memory_descriptor=
148+{
149+ MYSQL_AUDIT_INTERFACE_VERSION, /* interface version */
150+ NULL, /* release_thd function */
151+ slow_log_in_memory_notify, /* notify function */
152+ { (unsigned long) MYSQL_AUDIT_GENERAL_CLASSMASK } /* class mask */
153+};
154+
155+static void change_max_memory_for_slow_log(MYSQL_THD thd,
156+ SYS_VAR *var,
157+ void *ptr,
158+ const void *val)
159+{
160+ uint new_len= *(uint *)val;
161+ *(uint *)ptr= new_len;
162+
163+ global_slow_log_list->change_max_memory(new_len);
164+ return;
165+}
166+
167+static MYSQL_SYSVAR_UINT(max_memory, max_memory_for_slow_log,
168+ PLUGIN_VAR_OPCMDARG,
169+ "The max memory that can be allocated for slow log.",
170+ NULL, // check
171+ &change_max_memory_for_slow_log, // update
172+ 1024*1024, 0, 1024*1024*1024, 1);
173+
174+static SYS_VAR* slow_log_in_memory_system_vars[]= {
175+ MYSQL_SYSVAR(max_memory),
176+ NULL,
177+};
178+
179+static uint slow_log_current_memory(MYSQL_THD thd, SHOW_VAR *var, char *buff)
180+{
181+ var->type= SHOW_INT;
182+ var->value= (char*)&global_slow_log_list->current_memory;
183+ return 0;
184+}
185+
186+/* plugin status variables */
187+static SHOW_VAR slow_log_in_memory_status_vars[]= {
188+ {"slow_log_current_memory",
189+ (char*) &slow_log_current_memory,
190+ SHOW_FUNC},
191+ {NULL, NULL, SHOW_LONG},
192+};
193+
194+
195+/*
196+ I_S_SLOW_LOG
197+*/
198+static struct st_mysql_information_schema i_s_slow_log=
199+{
200+ MYSQL_INFORMATION_SCHEMA_INTERFACE_VERSION
201+};
202+
203+static ST_FIELD_INFO i_s_slow_log_fields[] =
204+{
205+ {"EVENT_ID", 11, MYSQL_TYPE_LONGLONG, 0, 0, 0, SKIP_OPEN_TABLE},
206+ {"TIMESTAMP", 11, MYSQL_TYPE_LONGLONG, 0, 0, 0, SKIP_OPEN_TABLE},
207+ {"THREAD_ID", 11, MYSQL_TYPE_LONG, 0, 0, 0, SKIP_OPEN_TABLE},
208+ {"DB", NAME_CHAR_LEN, MYSQL_TYPE_STRING, 0, 1, 0, SKIP_OPEN_TABLE},
209+ {"INNODB_TRX_ID", 11, MYSQL_TYPE_LONGLONG, 0, 1, 0, SKIP_OPEN_TABLE},
210+ {"ERRNO", 11, MYSQL_TYPE_LONG, 0, 0, 0, SKIP_OPEN_TABLE},
211+ {"MS_QUERY_TIME", 11, MYSQL_TYPE_FLOAT, 0, 0, 0, SKIP_OPEN_TABLE},
212+
213+ {"QUERY", 255, MYSQL_TYPE_STRING, 0, 1, 0, SKIP_OPEN_TABLE},
214+ {0, 0, MYSQL_TYPE_STRING, 0, 0, 0, SKIP_OPEN_TABLE}
215+};
216+
217+
218+int i_s_fill_table_slow_log(THD* thd, TABLE_LIST* tables, COND* cond)
219+{
220+ if (!global_slow_log_list) return 0;
221+
222+ TABLE *table= tables->table;
223+
224+ mysql_mutex_lock(&global_slow_log_list->LOCK_slow_log_);
225+
226+ slow_log_t *item= global_slow_log_list->first;
227+ while (item)
228+ {
229+ restore_record(table, s->default_values);
230+
231+ table->field[0]->store(item->event_id, TRUE);
232+ table->field[1]->store(item->timestamp, TRUE);
233+ table->field[2]->store(item->thread_id, TRUE);
234+
235+ if (item->schema)
236+ {
237+ table->field[3]->store(item->schema, item->schema_len-1, system_charset_info);
238+ table->field[3]->set_notnull();
239+ }
240+
241+ if (item->innodb_trx_id)
242+ {
243+ table->field[4]->store(item->innodb_trx_id, TRUE);
244+ table->field[4]->set_notnull();
245+ }
246+
247+ table->field[5]->store(item->cmd_errno, TRUE);
248+ table->field[6]->store(item->time_of_query);
249+
250+ if (item->general_query)
251+ {
252+ table->field[7]->store(item->general_query, item->general_query_len-1, system_charset_info);
253+ table->field[7]->set_notnull();
254+ }
255+
256+ schema_table_store_record(thd, table);
257+ item= item->next;
258+ }
259+
260+ mysql_mutex_unlock(&global_slow_log_list->LOCK_slow_log_);
261+ return 0;
262+}
263+
264+
265+static int i_s_slow_log_plugin_init(void *arg __attribute__((unused)))
266+{
267+ ST_SCHEMA_TABLE* schema;
268+
269+ schema = (ST_SCHEMA_TABLE*) arg;
270+
271+ schema->fields_info = i_s_slow_log_fields;
272+ schema->fill_table = i_s_fill_table_slow_log;
273+ return 0;
274+}
275+
276+
277+static int i_s_slow_log_plugin_deinit(void *arg __attribute__((unused)))
278+{
279+ return(0);
280+}
281+
282+/*
283+ Plugin library descriptor
284+*/
285+
286+mysql_declare_plugin(slow_log_in_memory)
287+{
288+ MYSQL_AUDIT_PLUGIN, /* type */
289+ &slow_log_in_memory_descriptor, /* descriptor */
290+ "SLOW_LOG_IN_MEMORY_AUDIT", /* name */
291+ "Percona", /* author */
292+ "Error code histogram Audit", /* description */
293+ PLUGIN_LICENSE_GPL,
294+ slow_log_in_memory_plugin_init, /* init function (when loaded) */
295+ slow_log_in_memory_plugin_deinit, /* deinit function (when unloaded) */
296+ 0x0001, /* version */
297+ slow_log_in_memory_status_vars, /* status variables */
298+ slow_log_in_memory_system_vars, /* system variables */
299+ NULL,
300+ 0,
301+},
302+{
303+ MYSQL_INFORMATION_SCHEMA_PLUGIN, /* type */
304+ &i_s_slow_log, /* descriptor */
305+ "SLOW_LOG", /* name */
306+ "Percona", /* author */
307+ "latest slow log in memory", /* description */
308+ PLUGIN_LICENSE_GPL,
309+ i_s_slow_log_plugin_init, /* init function (when loaded) */
310+ i_s_slow_log_plugin_deinit, /* deinit function (when unloaded) */
311+ 0x0001, /* version */
312+ NULL, /* status variables */
313+ NULL, /* system variables */
314+ NULL,
315+ 0,
316+}
317+mysql_declare_plugin_end;
318+
319--- a/plugin/slowlog_in_memory/ut_slow_log_list.h 1970-01-01 08:00:00.000000000 +0800
320+++ b/plugin/slowlog_in_memory/ut_slow_log_list.h 2011-12-22 21:09:34.000000000 +0800
321@@ -0,0 +1,230 @@
322+#ifndef UT_SLOW_LOG_LIST_H
323+#define UT_SLOW_LOG_LIST_H
324+
325+#define MYSQL_SERVER
326+#include <mysql/plugin_audit.h>
327+#include "unireg.h"
328+#include "sql_show.h"
329+#include "sql_class.h"
330+
331+mysql_mutex_t LOCK_slow_event_id_;
332+
333+#ifdef HAVE_PSI_INTERFACE
334+PSI_mutex_key key_ss_mutex_LOCK_slow_log_;
335+PSI_mutex_key key_ss_mutex_LOCK_slow_event_id_;
336+
337+static PSI_mutex_info all_semisync_mutexes[]=
338+{
339+ {&key_ss_mutex_LOCK_slow_log_, "LOCK_slow_log_", 0},
340+ {&key_ss_mutex_LOCK_slow_event_id_, "LOCK_slow_event_id_", 0}
341+};
342+
343+static void init_semisync_psi_keys(void)
344+{
345+ const char* category= "semisync";
346+ int count;
347+
348+ if (PSI_server == NULL)
349+ return;
350+
351+ count= array_elements(all_semisync_mutexes);
352+ PSI_server->register_mutex(category, all_semisync_mutexes, count);
353+
354+}
355+#endif /* HAVE_PSI_INTERFACE */
356+
357+/* unique event id for each slow query */
358+ulonglong global_event_id= 0;
359+
360+const uint MAX_QUERY_LEN= 255;
361+
362+class slow_log_t
363+{
364+public:
365+ ulonglong event_id;
366+ ulonglong timestamp;
367+ ulong thread_id;
368+ char *schema;
369+ ulonglong innodb_trx_id;
370+ int cmd_errno;
371+ double time_of_query;
372+ char *general_query;
373+
374+ uint schema_len;
375+ uint general_query_len;
376+
377+ slow_log_t *next;
378+
379+ slow_log_t(ulonglong timestamp, ulong thread_id, const char *schema,
380+ ulonglong innodb_trx_id, int cmd_errno, double time_of_query, const char *general_query):next(NULL)
381+ {
382+ this->timestamp= timestamp;
383+ this->thread_id= thread_id;
384+
385+ if (schema)
386+ {
387+ this->schema_len= strlen(schema) + 1;
388+ this->schema= strndup(schema, this->schema_len);
389+ }
390+ else
391+ {
392+ this->schema= NULL;
393+ this->schema_len= 0;
394+ }
395+
396+ this->innodb_trx_id= innodb_trx_id;
397+ this->cmd_errno= cmd_errno;
398+ this->time_of_query= time_of_query;
399+
400+ if (general_query)
401+ {
402+ this->general_query_len= strlen(general_query) + 1;
403+
404+ if (this->general_query_len > MAX_QUERY_LEN)
405+ {
406+ this->general_query_len= MAX_QUERY_LEN;
407+ }
408+
409+ this->general_query= strndup(general_query, this->general_query_len);
410+ this->general_query[this->general_query_len-1]= '\0';
411+ }
412+ else
413+ {
414+ this->general_query= NULL;
415+ this->general_query_len= 0;
416+ }
417+
418+ this->real_size= sizeof(slow_log_t) + this->schema_len + this->general_query_len;
419+
420+ mysql_mutex_lock(&LOCK_slow_event_id_);
421+ this->event_id= ++global_event_id;
422+ mysql_mutex_unlock(&LOCK_slow_event_id_);
423+ }
424+
425+ ~slow_log_t()
426+ {
427+ if (schema)
428+ {
429+ free(schema);
430+ schema= NULL;
431+ }
432+
433+ if (general_query)
434+ {
435+ free(general_query);
436+ general_query= NULL;
437+ }
438+ }
439+
440+ uint size_of_instance()
441+ {
442+ return real_size;
443+ }
444+
445+ uint real_size;
446+};
447+
448+class slow_log_list
449+{
450+public:
451+ slow_log_t *first, *last;
452+ mysql_mutex_t LOCK_slow_log_;
453+
454+ uint current_memory;
455+
456+ void change_max_memory(uint new_len)
457+ {
458+ mysql_mutex_lock(&LOCK_slow_log_);
459+
460+ max_memory= new_len;
461+
462+ /* if the size is larger than current size, just change the value*/
463+ if (max_memory >= current_memory)
464+ {
465+ mysql_mutex_unlock(&LOCK_slow_log_);
466+ return;
467+ }
468+
469+ while (current_memory > max_memory)
470+ {
471+ pop_front();
472+ }
473+
474+ mysql_mutex_unlock(&LOCK_slow_log_);
475+ }
476+
477+ slow_log_list(uint max_memory)
478+ {
479+ first= NULL;
480+ last= NULL;
481+ current_memory= 0;
482+ this->max_memory= max_memory;
483+
484+ mysql_mutex_init(key_ss_mutex_LOCK_slow_log_,
485+ &LOCK_slow_log_, MY_MUTEX_INIT_FAST);
486+ }
487+
488+ ~slow_log_list()
489+ {
490+ mysql_mutex_lock(&LOCK_slow_log_);
491+ while (first)
492+ {
493+ pop_front();
494+ }
495+ mysql_mutex_unlock(&LOCK_slow_log_);
496+
497+ mysql_mutex_destroy(&LOCK_slow_log_);
498+ }
499+
500+ void push_back(slow_log_t * item)
501+ {
502+ mysql_mutex_lock(&LOCK_slow_log_);
503+
504+ uint size= item->size_of_instance();
505+
506+ if (size > max_memory)
507+ {
508+ sql_print_warning("the insert item size %u > %u discarded", size, max_memory);
509+ mysql_mutex_unlock(&LOCK_slow_log_);
510+ return;
511+ }
512+
513+ while (current_memory + size > max_memory)
514+ {
515+ pop_front();
516+ }
517+
518+ if (!first)
519+ {
520+ first= item;
521+ last= item;
522+ }
523+ else
524+ {
525+ last->next= item;
526+ last= item;
527+ }
528+
529+ current_memory+= size;
530+ mysql_mutex_unlock(&LOCK_slow_log_);
531+ }
532+
533+ /*functions call pop_front should have hold LOCK_slow_log_*/
534+ void pop_front()
535+ {
536+ if (!first) return;
537+
538+ slow_log_t *item= first;
539+ first= first->next;
540+
541+ if (!first) last= NULL;
542+
543+ current_memory-= item->size_of_instance();
544+ delete item;
545+ }
546+
547+private:
548+ uint max_memory;
549+};
550+#endif
551+
552--- a/mysql-test/include/have_slog_log_in_memory_audit_plugin.inc 1970-01-01 08:00:00.000000000 +0800
553+++ b/mysql-test/include/have_slog_log_in_memory_audit_plugin.inc 2011-12-22 21:08:28.000000000 +0800
554@@ -0,0 +1,21 @@
555+#
556+# Check if server has support for loading plugins
557+#
558+if (`SELECT @@have_dynamic_loading != 'YES'`) {
559+ --skip Requires dynamic loading
560+}
561+
562+#
563+# Check if the variable SLOW_LOG_IN_MEMORY_AUDIT is set
564+#
565+if (!$SLOW_LOG_IN_MEMORY_AUDIT)
566+{
567+ skip Need slow_log_in_memory plugins;
568+}
569+
570+#
571+# Check if --plugin-dir was setup for slow_log_in_memory
572+#
573+if (`SELECT CONCAT('--plugin-dir=', @@plugin_dir) != '$SLOW_LOG_IN_MEMORY_AUDIT_OPT'`) {
574+ --skip SLOW_LOG plugin requires that --plugin-dir is set to the slow_log_in_memory plugin dir (either the .opt file does not contain \$SLOW_LOG_IN_MEMORY_AUDIT_OPT or another plugin is in use)
575+}
576--- a/mysql-test/include/plugin.defs 2011-12-19 14:44:49.000000000 +0800
577+++ b/mysql-test/include/plugin.defs 2011-12-22 21:08:28.000000000 +0800
578@@ -40,3 +40,5 @@
579 ha_federated storage/federated FEDERATED_PLUGIN
580 mypluglib plugin/fulltext SIMPLE_PARSER
581 libdaemon_example plugin/daemon_example DAEMONEXAMPLE
582+slowlog_in_memory plugin/slowlog_in_memory SLOW_LOG
583+slowlog_in_memory plugin/slowlog_in_memory SLOW_LOG_IN_MEMORY_AUDIT
584--- a/mysql-test/r/slow_log_in_memory.result 1970-01-01 08:00:00.000000000 +0800
585+++ b/mysql-test/r/slow_log_in_memory.result 2011-12-22 21:10:53.000000000 +0800
586@@ -0,0 +1,69 @@
587+#
588+# feature: slow log show in information_schema.slow_log
589+#
590+install plugin SLOW_LOG_IN_MEMORY_AUDIT soname 'slowlog_in_memory.so';
591+install plugin SLOW_LOG soname 'slowlog_in_memory.so';
592+show variables like 'slow_log_in_memory_audit_max_memory';
593+Variable_name Value
594+slow_log_in_memory_audit_max_memory 1048576
595+SET long_query_time=2;
596+SET query_exec_time=2.123456;
597+select 1;
598+1
599+1
600+SET query_exec_time=0;
601+SET long_query_time=2;
602+SET query_exec_time=2.1;
603+select 1;
604+1
605+1
606+SET query_exec_time=0;
607+SET long_query_time=2;
608+SET query_exec_time=2.1;
609+select 1;
610+1
611+1
612+SET query_exec_time=0;
613+show global status like 'slow_log_current_memory';
614+Variable_name Value
615+slow_log_current_memory XX
616+select * from information_schema.slow_log;
617+EVENT_ID TIMESTAMP THREAD_ID DB INNODB_TRX_ID ERRNO MS_QUERY_TIME QUERY
618+1 XX XX test XX 0 2.123456 select 1
619+2 XX XX test XX 0 2.1 select 1
620+3 XX XX test XX 0 2.1 select 1
621+# decrease max_memory and wash eldest
622+set global slow_log_in_memory_audit_max_memory=240;
623+use information_schema;
624+SET long_query_time=2;
625+SET query_exec_time=2.1;
626+select 1;
627+1
628+1
629+SET query_exec_time=0;
630+show global status like 'slow_log_current_memory';
631+Variable_name Value
632+slow_log_current_memory XX
633+select * from information_schema.slow_log;
634+EVENT_ID TIMESTAMP THREAD_ID DB INNODB_TRX_ID ERRNO MS_QUERY_TIME QUERY
635+3 XX XX test XX 0 2.1 select 1
636+4 XX XX information_schema XX 0 2.1 select 1
637+# set to zero to disable audit
638+set global slow_log_in_memory_audit_max_memory=0;
639+SET long_query_time=2;
640+SET query_exec_time=2.1;
641+select 1;
642+1
643+1
644+SET query_exec_time=0;
645+show global status like 'slow_log_current_memory';
646+Variable_name Value
647+slow_log_current_memory 0
648+select * from information_schema.slow_log;
649+EVENT_ID TIMESTAMP THREAD_ID DB INNODB_TRX_ID ERRNO MS_QUERY_TIME QUERY
650+uninstall plugin SLOW_LOG;
651+uninstall plugin SLOW_LOG_IN_MEMORY_AUDIT;
652+Warnings:
653+Warning 1620 Plugin is busy and will be uninstalled on shutdown
654+SET SESSION query_exec_time=default;
655+SET long_query_time=default;
656--- a/mysql-test/suite/sys_vars/r/slow_log_in_memory_audit.result 1970-01-01 08:00:00.000000000 +0800
657+++ b/mysql-test/suite/sys_vars/r/slow_log_in_memory_audit.result 2011-12-22 21:08:28.000000000 +0800
658@@ -0,0 +1,31 @@
659+install plugin SLOW_LOG_IN_MEMORY_AUDIT soname 'slowlog_in_memory.so';
660+install plugin SLOW_LOG soname 'slowlog_in_memory.so';
661+select @@global.slow_log_in_memory_audit_max_memory;
662+@@global.slow_log_in_memory_audit_max_memory
663+1048576
664+show global variables like 'slow_log_in_memory_audit_max_memory';
665+Variable_name Value
666+slow_log_in_memory_audit_max_memory 1048576
667+select * from information_schema.global_variables where variable_name='slow_log_in_memory_audit_max_memory';
668+VARIABLE_NAME VARIABLE_VALUE
669+SLOW_LOG_IN_MEMORY_AUDIT_MAX_MEMORY 1048576
670+set global slow_log_in_memory_audit_max_memory=2097152;
671+select @@global.slow_log_in_memory_audit_max_memory;
672+@@global.slow_log_in_memory_audit_max_memory
673+2097152
674+show global variables like 'slow_log_in_memory_audit_max_memory';
675+Variable_name Value
676+slow_log_in_memory_audit_max_memory 2097152
677+set global slow_log_in_memory_audit_max_memory=1.1;
678+ERROR 42000: Incorrect argument type to variable 'slow_log_in_memory_audit_max_memory'
679+set global slow_log_in_memory_audit_max_memory=1e1;
680+ERROR 42000: Incorrect argument type to variable 'slow_log_in_memory_audit_max_memory'
681+set global slow_log_in_memory_audit_max_memory="some text";
682+ERROR 42000: Incorrect argument type to variable 'slow_log_in_memory_audit_max_memory'
683+select @@global.slow_log_in_memory_audit_max_memory;
684+@@global.slow_log_in_memory_audit_max_memory
685+2097152
686+UNINSTALL PLUGIN SLOW_LOG;
687+UNINSTALL PLUGIN SLOW_LOG_IN_MEMORY_AUDIT;
688+Warnings:
689+Warning 1620 Plugin is busy and will be uninstalled on shutdown
690--- a/mysql-test/suite/sys_vars/t/slow_log_in_memory_audit-master.opt 1970-01-01 08:00:00.000000000 +0800
691+++ b/mysql-test/suite/sys_vars/t/slow_log_in_memory_audit-master.opt 2011-12-22 21:08:28.000000000 +0800
692@@ -0,0 +1 @@
693+$SLOW_LOG_IN_MEMORY_AUDIT_OPT
694--- a/mysql-test/suite/sys_vars/t/slow_log_in_memory_audit.test 1970-01-01 08:00:00.000000000 +0800
695+++ b/mysql-test/suite/sys_vars/t/slow_log_in_memory_audit.test 2011-12-22 21:08:28.000000000 +0800
696@@ -0,0 +1,40 @@
697+
698+#
699+# exists as a global only
700+#
701+source include/not_embedded.inc;
702+source include/have_slog_log_in_memory_audit_plugin.inc;
703+# The following is to prevent a mis-match on windows that has the name of of the lib ending with 'dll'
704+--replace_regex /\.dll/.so/
705+install plugin SLOW_LOG_IN_MEMORY_AUDIT soname 'slowlog_in_memory.so';
706+install plugin SLOW_LOG soname 'slowlog_in_memory.so';
707+select @@global.slow_log_in_memory_audit_max_memory;
708+
709+show global variables like 'slow_log_in_memory_audit_max_memory';
710+select * from information_schema.global_variables where variable_name='slow_log_in_memory_audit_max_memory';
711+
712+#
713+# show that it's writable
714+#
715+set global slow_log_in_memory_audit_max_memory=2097152;
716+select @@global.slow_log_in_memory_audit_max_memory;
717+show global variables like 'slow_log_in_memory_audit_max_memory';
718+
719+#
720+# incorrect types
721+#
722+--error ER_WRONG_TYPE_FOR_VAR
723+set global slow_log_in_memory_audit_max_memory=1.1;
724+--error ER_WRONG_TYPE_FOR_VAR
725+set global slow_log_in_memory_audit_max_memory=1e1;
726+--error ER_WRONG_TYPE_FOR_VAR
727+set global slow_log_in_memory_audit_max_memory="some text";
728+
729+
730+#
731+# Cleanup
732+#
733+select @@global.slow_log_in_memory_audit_max_memory;
734+UNINSTALL PLUGIN SLOW_LOG;
735+UNINSTALL PLUGIN SLOW_LOG_IN_MEMORY_AUDIT;
736+
737--- a/mysql-test/t/slow_log_in_memory-master.opt 1970-01-01 08:00:00.000000000 +0800
738+++ b/mysql-test/t/slow_log_in_memory-master.opt 2011-12-22 21:08:28.000000000 +0800
739@@ -0,0 +1 @@
740+$SLOW_LOG_IN_MEMORY_AUDIT_OPT
741--- a/mysql-test/t/slow_log_in_memory.test 1970-01-01 08:00:00.000000000 +0800
742+++ b/mysql-test/t/slow_log_in_memory.test 2011-12-22 21:10:45.000000000 +0800
743@@ -0,0 +1,61 @@
744+--source include/have_debug.inc
745+--source include/have_slog_log_in_memory_audit_plugin.inc
746+
747+--echo #
748+--echo # feature: slow log show in information_schema.slow_log
749+--echo #
750+
751+install plugin SLOW_LOG_IN_MEMORY_AUDIT soname 'slowlog_in_memory.so';
752+install plugin SLOW_LOG soname 'slowlog_in_memory.so';
753+show variables like 'slow_log_in_memory_audit_max_memory';
754+
755+SET long_query_time=2;
756+SET query_exec_time=2.123456;
757+select 1;
758+SET query_exec_time=0;
759+
760+connect (con1,localhost,root,,);
761+
762+SET long_query_time=2;
763+SET query_exec_time=2.1;
764+select 1;
765+SET query_exec_time=0;
766+
767+connect (con2,localhost,root,,);
768+
769+SET long_query_time=2;
770+SET query_exec_time=2.1;
771+select 1;
772+SET query_exec_time=0;
773+--replace_column 2 XX
774+show global status like 'slow_log_current_memory';
775+--replace_column 2 XX 3 XX 5 XX
776+select * from information_schema.slow_log;
777+
778+--echo # decrease max_memory and wash eldest
779+set global slow_log_in_memory_audit_max_memory=240;
780+connection con1;
781+use information_schema;
782+SET long_query_time=2;
783+SET query_exec_time=2.1;
784+select 1;
785+SET query_exec_time=0;
786+--replace_column 2 XX
787+show global status like 'slow_log_current_memory';
788+--replace_column 2 XX 3 XX 5 XX
789+select * from information_schema.slow_log;
790+
791+--echo # set to zero to disable audit
792+connection con1;
793+set global slow_log_in_memory_audit_max_memory=0;
794+SET long_query_time=2;
795+SET query_exec_time=2.1;
796+select 1;
797+SET query_exec_time=0;
798+show global status like 'slow_log_current_memory';
799+select * from information_schema.slow_log;
800+
801+uninstall plugin SLOW_LOG;
802+uninstall plugin SLOW_LOG_IN_MEMORY_AUDIT;
803+SET SESSION query_exec_time=default;
804+SET long_query_time=default;

Subscribers

People subscribed via source and target branches