query_log output is mangled due to multithreadedness
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Drizzle |
Fix Released
|
Medium
|
Stewart Smith |
Bug Description
When enabling query_log plugin and directing 32 sysbench threads against it, I get output like below:
# start_ts=
# session_id=12 query_id=11 rows_examined=1 rows_sent=1 tmp_tables=0 warnings=0
# execution_time=# start_ts=
# session_id=12 query_id=11 rows_examined=1 rows_sent=1 tmp_tables=HERE id=0lock_time=
warnings=0
# execution_
# error=false
# schema="sbtest"
SELECT pad FROM sbtest1 WHERE id=20176010;
#
# start_ts=
# session_id=12 query_id=11 rows_examined=1 rows_sent=1 tmp_tables=0 warnings=0
# execution_time=# start_ts=
# session_id=12 query_id=11 rows_examined=1 rows_sent=1 tmp_tables=HERE id=0lock_time=
warnings=0
# execution_
# error=false
# schema="sbtest"
SELECT pad FROM sbtest1 WHERE id=20176010;
#
0.031333 lock_time=0.002518 session_
# error=false
# schema="sbtest"
SELECT pad FROM sbtest1 WHERE id=20176010;
#
....
It seems that output from multiple threads is mixed together.
Related branches
- Drizzle Trunk: Pending requested
-
Diff: 139 lines (+56/-31)2 files modifiedplugin/query_log/file.cc (+55/-30)
plugin/query_log/file.h (+1/-1)
tags: | added: query-log-plugin |
Changed in drizzle: | |
status: | New → Fix Committed |
importance: | Undecided → Medium |
assignee: | nobody → Stewart Smith (stewart) |
milestone: | none → 7.2.5 |
Changed in drizzle: | |
status: | Fix Committed → Fix Released |
Henrik,
Does logging_query have this problem too? Its code says:
// a single write has a kernel thread lock, thus no need mutex guard this
wrv= write(fd, msgbuf.c_str(), msgbuf.length());
assert(wrv == msgbuf.length());
Whereas query_log does,
_fh << "# start_ts=" << event->ts
...
which isn't thread-safe (and yes, that's my fault :-). If write() is indeed thread-safe, then it will be easy to make query_log use it like logginq_query.