Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix write event log and audit log coredump(the events.logfile&audit.… #2427

Merged
merged 1 commit into from
Dec 2, 2019
Merged

Conversation

bskllzh
Copy link
Contributor

@bskllzh bskllzh commented Dec 2, 2019

…logfile null pointer)

Bug description:
When i make a benchmark test with a sysbench(version: 1.0.17) in proxysql 2.0.8 + mysql 5.7.26, i get the follow error info:
Error: signal 11:
proxysql(_Z13crash_handleri+0x25)[0x5b607c]
/lib64/libc.so.6(+0x35270)[0x2b673de34270]
/lib64/libstdc++.so.6(_ZNSo6sentryC2ERSo+0xf)[0x2b673d67521f]
/lib64/libstdc++.so.6(_ZNSo5writeEPKcl+0x31)[0x2b673d675621]
proxysql(_ZN11MySQL_Event20write_query_format_1EPSt13basic_fstreamIcSt11char_traitsIcEE+0x27d)[0x6e2d81]
proxysql(_ZN11MySQL_Event5writeEPSt13basic_fstreamIcSt11char_traitsIcEEP13MySQL_Session+0x79)[0x6e19e9]
proxysql(_ZN12MySQL_Logger11log_requestEP13MySQL_SessionP17MySQL_Data_Stream+0x710)[0x6e5416]
proxysql(_ZN13MySQL_Session8LogQueryEP17MySQL_Data_Stream+0x6d)[0x654055]
proxysql(_ZN13MySQL_Session10RequestEndEP17MySQL_Data_Stream+0x35)[0x6540d7]
proxysql(_ZN13MySQL_Session7handlerEv+0x4397)[0x6459ed]
proxysql(_ZN12MySQL_Thread20process_all_sessionsEv+0x830)[0x623180]
proxysql(_ZN12MySQL_Thread3runEv+0x2cbe)[0x62208a]
proxysql(_Z24mysql_worker_thread_funcPv+0xbb)[0x5afb05]
/lib64/libpthread.so.0(+0x7e25)[0x2b673cda8e25]
/lib64/libc.so.6(clone+0x6d)[0x2b673def734d]
2019-12-02 09:52:26 main.cpp:1396:ProxySQL_daemonize_phase3(): [ERROR] ProxySQL crashed. Restarting!

I analyze the coredump with proxysql 2.0.8 debug version very carefully, and i found the variable of events.logfile is null pointer in log_request function when it call write function(me.write(events.logfile, sess)). The following is the coredump(write (this=0x2b67402fd1f0, f=0x0, sess=0x2b67414a8c00)):
(gdb) bt
#0 0x00002b673d67521f in std::ostream::sentry::sentry(std::ostream&) () from /lib64/libstdc++.so.6
#1 0x00002b673d675621 in std::ostream::write(char const*, long) () from /lib64/libstdc++.so.6
#2 0x00000000006e2d81 in MySQL_Event::write_query_format_1 (this=0x2b67402fd1f0, f=0x0) at MySQL_Logger.cpp:265
#3 0x00000000006e19e9 in MySQL_Event::write (this=0x2b67402fd1f0, f=0x0, sess=0x2b67414a8c00) at MySQL_Logger.cpp:89
#4 0x00000000006e5416 in MySQL_Logger::log_request (this=0x2b673e419680, sess=0x2b67414a8c00, myds=0x2b6741346480)
at MySQL_Logger.cpp:717
#5 0x0000000000654055 in MySQL_Session::LogQuery (this=0x2b67414a8c00, myds=0x2b6741346480) at MySQL_Session.cpp:6691
#6 0x00000000006540d7 in MySQL_Session::RequestEnd (this=0x2b67414a8c00, myds=0x2b6741346480) at MySQL_Session.cpp:6711
#7 0x00000000006459ed in MySQL_Session::handler (this=0x2b67414a8c00) at MySQL_Session.cpp:4086
#8 0x0000000000623180 in MySQL_Thread::process_all_sessions (this=0x2b6741301000) at MySQL_Thread.cpp:4392
#9 0x000000000062208a in MySQL_Thread::run (this=0x2b6741301000) at MySQL_Thread.cpp:4125
#10 0x00000000005afb05 in mysql_worker_thread_func (arg=0x2b673e461f30) at main.cpp:648
#11 0x00002b673cda8e25 in start_thread () from /lib64/libpthread.so.0
#12 0x00002b673def734d in clone () from /lib64/libc.so.6

And then i add a line of code in log_request function of MySQL_Logger.cpp file to check up whether events.logfile is null pointer ,as follow:
void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds) {
if (events.enabled==false) return;
if (events.logfile==NULL) return;

proxy_info("log_request: First: events.logfile is null %d\n", (events.logfile == NULL) ? 1 : 0);
MySQL_Connection_userinfo *ui=sess->client_myds->myconn->userinfo;

And i make a benchmark test again with proxysql 2.0.8 debug version, the coredump of proxysql happen again, then i get the follow print info from proxysql.log
[root@XXXXX proxysql]# grep -n -w 'log_request: First: events.logfile is null 1' proxysql.log
7358447:2019-12-02 09:52:26 MySQL_Logger.cpp:617:log_request(): [INFO] log_request: First: events.logfile is null 1
7358448:2019-12-02 09:52:26 MySQL_Logger.cpp:617:log_request(): [INFO] log_request: First: events.logfile is null 1

Bux fix:
Fix write event log and audit log coredump, because the proxysql get the null pointer variable of events.logfile(audit.logfile)in a multithreaded environment.

…ogfile null pointer)

Bug description:
When i make a benchmark test with a sysbench(version: 1.0.17) in proxysql 2.0.8   + mysql 5.7.26, i get the follow error info: 
Error: signal 11:
proxysql(_Z13crash_handleri+0x25)[0x5b607c]
/lib64/libc.so.6(+0x35270)[0x2b673de34270]
/lib64/libstdc++.so.6(_ZNSo6sentryC2ERSo+0xf)[0x2b673d67521f]
/lib64/libstdc++.so.6(_ZNSo5writeEPKcl+0x31)[0x2b673d675621]
proxysql(_ZN11MySQL_Event20write_query_format_1EPSt13basic_fstreamIcSt11char_traitsIcEE+0x27d)[0x6e2d81]
proxysql(_ZN11MySQL_Event5writeEPSt13basic_fstreamIcSt11char_traitsIcEEP13MySQL_Session+0x79)[0x6e19e9]
proxysql(_ZN12MySQL_Logger11log_requestEP13MySQL_SessionP17MySQL_Data_Stream+0x710)[0x6e5416]
proxysql(_ZN13MySQL_Session8LogQueryEP17MySQL_Data_Stream+0x6d)[0x654055]
proxysql(_ZN13MySQL_Session10RequestEndEP17MySQL_Data_Stream+0x35)[0x6540d7]
proxysql(_ZN13MySQL_Session7handlerEv+0x4397)[0x6459ed]
proxysql(_ZN12MySQL_Thread20process_all_sessionsEv+0x830)[0x623180]
proxysql(_ZN12MySQL_Thread3runEv+0x2cbe)[0x62208a]
proxysql(_Z24mysql_worker_thread_funcPv+0xbb)[0x5afb05]
/lib64/libpthread.so.0(+0x7e25)[0x2b673cda8e25]
/lib64/libc.so.6(clone+0x6d)[0x2b673def734d]
2019-12-02 09:52:26 main.cpp:1396:ProxySQL_daemonize_phase3(): [ERROR] ProxySQL crashed. Restarting!

I analyze the coredump with proxysql 2.0.8 debug version  very carefully, and  i found the variable of events.logfile  is null pointer in log_request  function when it call write function(me.write(events.logfile, sess)). The following is the coredump(write (this=0x2b67402fd1f0, f=0x0, sess=0x2b67414a8c00)):
(gdb) bt
#0  0x00002b673d67521f in std::ostream::sentry::sentry(std::ostream&) () from /lib64/libstdc++.so.6
#1  0x00002b673d675621 in std::ostream::write(char const*, long) () from /lib64/libstdc++.so.6
#2  0x00000000006e2d81 in MySQL_Event::write_query_format_1 (this=0x2b67402fd1f0, f=0x0) at MySQL_Logger.cpp:265
#3  0x00000000006e19e9 in MySQL_Event::write (this=0x2b67402fd1f0, f=0x0, sess=0x2b67414a8c00) at MySQL_Logger.cpp:89
#4  0x00000000006e5416 in MySQL_Logger::log_request (this=0x2b673e419680, sess=0x2b67414a8c00, myds=0x2b6741346480)
    at MySQL_Logger.cpp:717
#5  0x0000000000654055 in MySQL_Session::LogQuery (this=0x2b67414a8c00, myds=0x2b6741346480) at MySQL_Session.cpp:6691
#6  0x00000000006540d7 in MySQL_Session::RequestEnd (this=0x2b67414a8c00, myds=0x2b6741346480) at MySQL_Session.cpp:6711
#7  0x00000000006459ed in MySQL_Session::handler (this=0x2b67414a8c00) at MySQL_Session.cpp:4086
#8  0x0000000000623180 in MySQL_Thread::process_all_sessions (this=0x2b6741301000) at MySQL_Thread.cpp:4392
#9  0x000000000062208a in MySQL_Thread::run (this=0x2b6741301000) at MySQL_Thread.cpp:4125
#10 0x00000000005afb05 in mysql_worker_thread_func (arg=0x2b673e461f30) at main.cpp:648
#11 0x00002b673cda8e25 in start_thread () from /lib64/libpthread.so.0
#12 0x00002b673def734d in clone () from /lib64/libc.so.6

And then i add a line of code in log_request function of MySQL_Logger.cpp file to check up whether events.logfile is null pointer ,as follow:
void MySQL_Logger::log_request(MySQL_Session *sess, MySQL_Data_Stream *myds) {
	if (events.enabled==false) return;
	if (events.logfile==NULL) return;

    proxy_info("log_request: First: events.logfile is null %d\n", (events.logfile == NULL) ? 1 : 0);
	MySQL_Connection_userinfo *ui=sess->client_myds->myconn->userinfo;

And i make a benchmark test  again with proxysql 2.0.8 debug version, the coredump of proxysql happen again, then i get the follow print info from proxysql.log
[root@XXXXX proxysql]# grep -n -w 'log_request: First: events.logfile is null 1' proxysql.log   
7358447:2019-12-02 09:52:26 MySQL_Logger.cpp:617:log_request(): [INFO] log_request: First: events.logfile is null 1
7358448:2019-12-02 09:52:26 MySQL_Logger.cpp:617:log_request(): [INFO] log_request: First: events.logfile is null 1

Bux fix:
Fix write event log and audit log  coredump, because  the proxysql get the null pointer variable of events.logfile(audit.logfile)in a multithreaded environment.
@pondix
Copy link
Contributor

pondix commented Dec 2, 2019

Automated message: PR pending admin approval for build testing

@renecannao
Copy link
Contributor

add to whitelist

@renecannao
Copy link
Contributor

@bskllzh : I think you spot an interesting bug, thank you for the bug fix

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants