Crash using logging_query plugin and drizzledump

[fmpwizard]

session->query was being assigned <Address 0x15 out of bounds> when you had a new thread and new session.

This causes a crash when you use the logging query plugin (as well as the gearman and syslog plugins) and drizzledump.
The crash happens when you try to get strlen(query), as query is an address out of bounds, drizzled crashes.

How to repeat:

1- Start Drizzle and create this database and table

CREATE DATABASE test;
USE test;
CREATE TABLE t1 (a int);

2- On another terminal, run this loop:
$ while [ true ]; do
    ./drizzle/bin/drizzledump --no-defaults -uroot --port=3306 --compact test t1;
  done;

Short after you start the loop, you will see this message printing on the screen

$ drizzledump: Got error: 21 when trying to connect
You can ctrl + c to stop it.

And drizzle crashed.

Suggest fix:
After looking at this for days, the best solution I found was to add
query= NULL to
drizzled/session.cc:225
(near query_id= 0; )
My thinking was that query was not being initialized when a new session started.

If drizzle did not crashed, it then added wrong entries to the log files:

1251838210662827,768,65913,"drizzleslap","CREATE SCHEMA `###","Init DB",18374060420741521834,367,367,0,0,0,0,1

That entry shows part of the "previous" query, as the query text for a Inint DB command.

============================
Extra debugging information:

Program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: KERN_PROTECTION_FAILURE at address: 0x00000010
[Switching to process 46525 thread 0x2807]
0x95bdcf30 in strlen ()
(gdb) bt
#0 0x95bdcf30 in strlen ()
#1 0x001b4a40 in Session::getQueryLength (this=0x104b000) at session.h:787
#2 0x0034960c in Logging_query::post (this=0xf19430, session=0x104b000) at plugin/logging_query/logging_query.cc:283
#3 0x000d5437 in LoggingPostIterate::operator() (this=0xb0524df8, handler=0xf19430) at logging.cc:79
#4 0x000d5647 in std::find_if<__gnu_cxx::__normal_iterator<Logging_handler**, std::vector<Logging_handler*, std::allocator<Logging_handler*> > >, LoggingPostIterate> (__first={_M_current = 0xf179b4}, __last={_M_current = 0xf179bc}, __pred={<std::unary_function<Logging_handler*,bool>> = {<No data fields>}, session = 0x104b000}) at stl_algo.h:283
#5 0x000d56ce in std::find_if<__gnu_cxx::__normal_iterator<Logging_handler**, std::vector<Logging_handler*, std::allocator<Logging_handler*> > >, LoggingPostIterate> (__first={_M_current = 0xf179b0}, __last={_M_current = 0xf179bc}, __pred={<std::unary_function<Logging_handler*,bool>> = {<No data fields>}, session = 0x104b000}) at stl_algo.h:337
#6 0x000d4bb7 in logging_post_do (session=0x104b000) at logging.cc:115
#7 0x00142455 in dispatch_command (command=COM_INIT_DB, session=0x104b000, packet=0x226b001 "", packet_length=4) at sql_parse.cc:294
#8 0x001030dc in Session::executeStatement (this=0x104b000) at session.cc:724
#9 0x0010380f in Session::run (this=0x104b000) at session.cc:599
#10 0x0034c1b5 in MultiThreadScheduler::runSession (this=0x2d19610, session=0x104b000) at plugin/multi_thread/multi_thread.cc:102
#11 0x0034aefb in session_thread (arg=0x104b000) at plugin/multi_thread/multi_thread.cc:123
#12 0x95c05155 in _pthread_start ()
#13 0x95c05012 in thread_start ()

======================

(gdb) bt full
#0 0x95bdcf30 in strlen ()
No symbol table info available.
#1 0x001b4a40 in Session::getQueryLength (this=0x104b000) at session.h:787
No locals.
#2 0x0034960c in Logging_query::post (this=0xf19430, session=0x104b000) at plugin/logging_query/logging_query.cc:283
        msgbuf = '\0' <repeats 29407 times>, "\001\000\000\000\001\000\000\000x?R##XHR#\037FR#\001", '\0' <repeats 35 times>, "T###\000\000\000\000 FR#(FR#\000\000\000\000\005\000\000\000\005\000\000\000##R##hIR#kFR#\005\000\000\000^####GR##FR#", '\0' <repeats 20 times>, "T###\000\000\000\000pFR#xFR#\000\000\000\000\000\000\000\000pFR#\005\000\000\000\005\000\000\000\005\000\000\000\004HR#(GR#^###\004HR###R#", '\0' <repeats 36 times>, "#####\000\000\000\037FR#\000\000\000"...
        msgbuf_len = 0
        wrv = 67108864
        t_mark = 1251912774966650
        qs = '\0' <repeats 15 times>, "###\002\002\000\000\000@###002###\002\001", '\0' <repeats 11 times>, "##4", '\0' <repeats 25 times>, "###\0020y##002\000\000##002\000\000\000\0000y##0020y##002E###002###\002P\000\002\000\002\000\000\000 ", '\0' <repeats 11 times>, "####002\000\000##002\000\000\000\000####002####0028\000###00\000\000\000\000#####000\000\000\0008\000###00\000\000\000\000\000Do#4###\000\000###00\000\000\000\000(MR#####8\000###00\000###002(MR#2###\037MR#NMR#\000Do#\000\000\000"...
        dbs = 0x2d196e0 "test"
        dbl = 4
        ln = 2958183784
        Logging_query::post(Session*)::__func__ = "post"
#3 0x000d5437 in LoggingPostIterate::operator() (this=0xb0524df8, handler=0xf19430) at logging.cc:79
No locals.
#4 0x000d5647 in std::find_if<__gnu_cxx::__normal_iterator<Logging_handler**, std::vector<Logging_handler*, std::allocator<Logging_handler*> > >, LoggingPostIterate> (__first={_M_current = 0xf179b4}, __last={_M_current = 0xf179bc}, __pred={<std::unary_function<Logging_handler*,bool>> = {<No data fields>}, session = 0x104b000}) at stl_algo.h:283
        __trip_count = 0
#5 0x000d56ce in std::find_if<__gnu_cxx::__normal_iterator<Logging_handler**, std::vector<Logging_handler*, std::allocator<Logging_handler*> > >, LoggingPostIterate> (__first={_M_current = 0xf179b0}, __last={_M_current = 0xf179bc}, __pred={<std::unary_function<Logging_handler*,bool>> = {<No data fields>}, session = 0x104b000}) at stl_algo.h:337
No locals.
#6 0x000d4bb7 in logging_post_do (session=0x104b000) at logging.cc:115
        iter = {
  _M_current = 0x104b742
}
#7 0x00142455 in dispatch_command (command=COM_INIT_DB, session=0x104b000, packet=0x226b001 "", packet_length=4) at sql_parse.cc:294
        error = false
        query_id = (Query_id &) @0x557000: {
  the_query_id = {
    <drizzled::internal::atomic_impl<long long unsigned int,long long unsigned int,drizzled::internal::pthread_traits<long long unsigned int, long long unsigned int> >> = {
      <drizzled::internal::atomic_base<long long unsigned int>> = {
        my_value = 758
      },
      members of drizzled::internal::atomic_impl<long long unsigned int,long long unsigned int,drizzled::internal::pthread_traits<long long unsigned int, long long unsigned int> >:
      traits = {
        my_lock = {
          the_mutex = {
            __sig = 1297437784,
            __opaque = '\0' <repeats 16 times>, " ", '\0' <repeats 22 times>
          },
          locked = false
        }
      }
    }, <No data fields>}
}
        dispatch_command(enum_server_command, Session*, char*, unsigned int)::__func__ = "dispatch_command"
#8 0x001030dc in Session::executeStatement (this=0x104b000) at session.cc:724
        l_packet = 0x226b000 "\a"
        packet_length = 5
        l_command = COM_INIT_DB
        Session::executeStatement()::__func__ = "executeStatement"
#9 0x0010380f in Session::run (this=0x104b000) at session.cc:599
No locals.
#10 0x0034c1b5 in MultiThreadScheduler::runSession (this=0x2d19610, session=0x104b000) at plugin/multi_thread/multi_thread.cc:102
No locals.
#11 0x0034aefb in session_thread (arg=0x104b000) at plugin/multi_thread/multi_thread.cc:123
        session = (Session *) 0x104b000
        scheduler = (MultiThreadScheduler *) 0x2d19610
#12 0x95c05155 in _pthread_start ()
No symbol table info available.
#13 0x95c05012 in thread_start ()
No symbol table info available.

================
Looking at gdb, I see this:

[Switching to process 52177 thread 0x27ab]
Breakpoint 1, session_thread (arg=0x1024000) at plugin/multi_thread/multi_thread.cc:123
123 scheduler->runSession(session);
(gdb) c
Continuing.
[Switching to process 52177 thread 0x27af]
Breakpoint 1, session_thread (arg=0x1024000) at plugin/multi_thread/multi_thread.cc:123
123 scheduler->runSession(session);
(gdb) c
Continuing.
[Switching to process 52177 thread 0x2807]
Breakpoint 1, session_thread (arg=0x104b200) at plugin/multi_thread/multi_thread.cc:123
123 scheduler->runSession(session);
(gdb) c
Continuing.
Program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: KERN_PROTECTION_FAILURE at address: 0x00000010
0x95bdcf30 in strlen ()

Note that once the thread goes from 0x27af to 0x2807, session_thread goes from 0x1024000 to 0x104b200.
At that point, if I do
(gdb)print session->query
I get <Address 0x15 out of bounds> and soon after that, a crash when trying to do strlen(query) on session.h

If at the time I find that session_query is pointing to an address out of bound, I do

(gdb)set session->query=SELECT 1
(gdb)cont
It all goes well, I see the query text SELECT 1 on the logs, and a Query type of INIT_DB

[fmpwizard (diego-fmpwizard)]

revno: 1129
committer: Diego Medina <email address hidden>
branch nick: bug-fixes
timestamp: Thu 2009-09-03 00:00:45 -0400
message:
  Fixes bug #423502 - Crash using logging_query plugin and drizzledump
modified:
  drizzled/session.cc