Invalid write/read of size 1/8 in do_lookup_x and _dl_name_match_p

[Roel Van de Paar]

==1078== Invalid write of size 1
==1078== at 0x3DA1009777: do_lookup_x (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA100A072: _dl_lookup_symbol_x (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA100E2D3: _dl_fixup (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA10148E4: _dl_runtime_resolve (in /usr/lib64/ld-2.15.so)
==1078== by 0x7B0BF9: my_pthread_fastmutex_lock (thr_mutex.c:481)
==1078== by 0x712B67: inline_mysql_mutex_lock.constprop.125 (mysql_thread.h:617)
==1078== by 0x71CAC5: vprint_msg_to_log(loglevel, char const*, __va_list_tag*) (log.cc:6304)
==1078== by 0x71CBE0: Log_to_file_event_handler::log_error(loglevel, char const*, __va_list_tag*) (log.cc:938)
==1078== by 0x713693: LOGGER::error_log_print(loglevel, char const*, __va_list_tag*) (log.cc:1052)
==1078== by 0x715897: error_log_print(loglevel, char const*, __va_list_tag*) (log.cc:5273)
==1078== by 0x7159D2: sql_print_warning(char const*, ...) (log.cc:6380)
==1078== by 0x52E979: mysqld_get_one_option (mysqld.cc:7193)
==1078== by 0x7A4D63: handle_options (my_getopt.c:738)
==1078== by 0x530529: init_common_variables() (mysqld.cc:7530)
==1078== by 0x5346DC: mysqld_main(int, char**) (mysqld.cc:4600)
==1078== by 0x3DA1421734: (below main) (in /usr/lib64/libc-2.15.so)
==1078== Address 0x7feffcef0 is on thread 1's stack
==1078==
==1078== Invalid write of size 8
==1078== at 0x3DA1009785: do_lookup_x (in /usr/lib64/ld-2.15.so)
==1078== by 0x4: ???
==1078== by 0x4C21D9F: ???
==1078== by 0x107019F: ???
==1078== by 0x7FEFFD1DF: ???
==1078== Address 0x7feffcee8 is on thread 1's stack
==1078==
==1078== Invalid read of size 8
==1078== at 0x3DA100FF9A: _dl_name_match_p (in /usr/lib64/ld-2.15.so)
==1078== Address 0x7feffcee8 is on thread 1's stack
==1078==
==1078== Invalid read of size 1
==1078== at 0x3DA100978C: do_lookup_x (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA100A072: _dl_lookup_symbol_x (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA100E2D3: _dl_fixup (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA10148E4: _dl_runtime_resolve (in /usr/lib64/ld-2.15.so)
==1078== by 0x7B0BF9: my_pthread_fastmutex_lock (thr_mutex.c:481)
==1078== by 0x712B67: inline_mysql_mutex_lock.constprop.125 (mysql_thread.h:617)
==1078== by 0x71CAC5: vprint_msg_to_log(loglevel, char const*, __va_list_tag*) (log.cc:6304)
==1078== by 0x71CBE0: Log_to_file_event_handler::log_error(loglevel, char const*, __va_list_tag*) (log.cc:938)
==1078== by 0x713693: LOGGER::error_log_print(loglevel, char const*, __va_list_tag*) (log.cc:1052)
==1078== by 0x715897: error_log_print(loglevel, char const*, __va_list_tag*) (log.cc:5273)
==1078== by 0x7159D2: sql_print_warning(char const*, ...) (log.cc:6380)
==1078== by 0x52E979: mysqld_get_one_option (mysqld.cc:7193)
==1078== by 0x7A4D63: handle_options (my_getopt.c:738)
==1078== by 0x530529: init_common_variables() (mysqld.cc:7530)
==1078== by 0x5346DC: mysqld_main(int, char**) (mysqld.cc:4600)
==1078== by 0x3DA1421734: (below main) (in /usr/lib64/libc-2.15.so)
==1078== Address 0x7feffcef0 is on thread 1's stack
==1078==
==1078== Invalid write of size 1
==1078== at 0x3DA1009DC6: do_lookup_x (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA100A072: _dl_lookup_symbol_x (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA100E2D3: _dl_fixup (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA10148E4: _dl_runtime_resolve (in /usr/lib64/ld-2.15.so)
==1078== by 0x7B0BF9: my_pthread_fastmutex_lock (thr_mutex.c:481)
==1078== by 0x712B67: inline_mysql_mutex_lock.constprop.125 (mysql_thread.h:617)
==1078== by 0x71CAC5: vprint_msg_to_log(loglevel, char const*, __va_list_tag*) (log.cc:6304)
==1078== by 0x71CBE0: Log_to_file_event_handler::log_error(loglevel, char const*, __va_list_tag*) (log.cc:938)
==1078== by 0x713693: LOGGER::error_log_print(loglevel, char const*, __va_list_tag*) (log.cc:1052)
==1078== by 0x715897: error_log_print(loglevel, char const*, __va_list_tag*) (log.cc:5273)
==1078== by 0x7159D2: sql_print_warning(char const*, ...) (log.cc:6380)
==1078== by 0x52E979: mysqld_get_one_option (mysqld.cc:7193)
==1078== by 0x7A4D63: handle_options (my_getopt.c:738)
==1078== by 0x530529: init_common_variables() (mysqld.cc:7530)
==1078== by 0x5346DC: mysqld_main(int, char**) (mysqld.cc:4600)
==1078== by 0x3DA1421734: (below main) (in /usr/lib64/libc-2.15.so)
==1078== Address 0x7feffcef0 is on thread 1's stack
==1078==
==1078== Invalid read of size 1
==1078== at 0x3DA1009DFD: do_lookup_x (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA100A072: _dl_lookup_symbol_x (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA100E2D3: _dl_fixup (in /usr/lib64/ld-2.15.so)
==1078== by 0x3DA10148E4: _dl_runtime_resolve (in /usr/lib64/ld-2.15.so)
==1078== by 0x7B0BF9: my_pthread_fastmutex_lock (thr_mutex.c:481)
==1078== by 0x712B67: inline_mysql_mutex_lock.constprop.125 (mysql_thread.h:617)
==1078== by 0x71CAC5: vprint_msg_to_log(loglevel, char const*, __va_list_tag*) (log.cc:6304)
==1078== by 0x71CBE0: Log_to_file_event_handler::log_error(loglevel, char const*, __va_list_tag*) (log.cc:938)
==1078== by 0x713693: LOGGER::error_log_print(loglevel, char const*, __va_list_tag*) (log.cc:1052)
==1078== by 0x715897: error_log_print(loglevel, char const*, __va_list_tag*) (log.cc:5273)
==1078== by 0x7159D2: sql_print_warning(char const*, ...) (log.cc:6380)
==1078== by 0x52E979: mysqld_get_one_option (mysqld.cc:7193)
==1078== by 0x7A4D63: handle_options (my_getopt.c:738)
==1078== by 0x530529: init_common_variables() (mysqld.cc:7530)
==1078== by 0x5346DC: mysqld_main(int, char**) (mysqld.cc:4600)
==1078== by 0x3DA1421734: (below main) (in /usr/lib64/libc-2.15.so)
==1078== Address 0x7feffcef0 is on thread 1's stack

[Roel Van de Paar (roel11)]

Testcase is easy:

$ cat start_mtr98
cd /ssd/Percona-Server-5.5.28-rel29.3-415.Linux.x86_64/mysql-test/
perl lib/v1/mysql-test-run.pl --start-and-exit --valgrind --mysqld=--relay-log=slave-relay-bin --mysqld=--abort-slave-event-count=10 --mysqld=--log-queries-not-using-indexes --mysqld=--secure-file-priv= --mysqld=--max-allowed-packet=16Mb --mysqld=--loose-innodb-status-file=1 --mysqld=--master-retry-count=65535 --mysqld=--loose-debug-assert-if-crashed-table --mysqld=--loose-debug-assert-on-error --mysqld=--skip-name-resolve --vardir=/ssd/775838/vardir1_98 --master_port=17001--mysqld="--log-output=none" --mysqld="--sql_mode=ONLY_FULL_GROUP_BY" --mysqld="--innodb-max-bitmap-file-size=4095" --mysqld="--innodb-changed-pages-limit=-1" 1st 2>&1
$ cat stop_mtr98
/ssd/Percona-Server-5.5.28-rel29.3-415.Linux.x86_64/bin/mysqladmin -uroot -S/ssd/775838/vardir1_98/tmp/master.sock shutdown
$ ./start_mtr98;./stop_mtr98
$ vi /ssd/775838/vardir1_98/log/master.err # And see Valgrind error

This seems to have something to do with the length of the startup command & option parsing. For example, though the server does not start with the following command, it/this also produces the same Valgrind warning :

$ cat start_mtr98.safe.2
cd /ssd/Percona-Server-5.5.28-rel29.3-415.Linux.x86_64/mysql-test/
perl lib/v1/mysql-test-run.pl --start-and-exit --valgrind --mysqld=--relay-log=slave-relay-bin --mysqld=--aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa --mysqld=--secure-file-priv= --mysqld=--max-allowed-packet=16Mb --mysqld=--loose-innodb-status-file=1 --mysqld=--master-retry-count=
65535 --mysqld=--loose-debug-assert-if-crashed-table --mysqld=--loose-debug-assert-on-error --mysqld=--skip-name-resolve --vardir=/ssd/775838/vardir1_98 --master_port=17001 --mysqld="--log-output=none" --mysqld="--sql_mode=ONLY_FULL_GROUP_BY" --mysqld="--innodb-max-bitmap-file-size=4095" --mysqld="--innodb-changed-pages-limit=-1" 1st 2>&1

However, when reducing the length of 'aaaaa..aaaaa' the Valgrind error disappears.

[Roel Van de Paar (roel11)]

Reducing the 'aaaa' string to: --mysqld=--aaaaaaaaaaaaaaaaaaaaaaaaaaaaaa removes the Valgrind warning. Adding 10x 'a' and it happens again.

[Laurynas Biveinis (laurynas-biveinis)]

Cannot reproduce using an MTR testcase:

$ cat percona_bug1102776.test
SELECT 2+2;
$ cat percona_bug1102776-master.opt
--aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa --relay-log=slave-relay-bin --abort-slave-event-count=10 --log-queries-not-using-indexes --secure-file-priv= --max-allowed-packet=16Mb --loose-innodb-status-file=1 --master-retry-count=65535 --loose-debug-assert-if-crashed-table --loose-debug-assert-on-error --skip-name-resolve --log-output=none --sql_mode=ONLY_FULL_GROUP_BY --innodb-max-bitmap-file-size=4095 --innodb-changed-pages-limit=-1

Gives a Valgrind-clean run. So does start_mtr98 (but using mysql-test-run instead of lib/v1/mysql-test-run.pl)

[Laurynas Biveinis (laurynas-biveinis)]

Also, how is the server built?

[Laurynas Biveinis (laurynas-biveinis)]

Cannot reproduce using v1 runner:
export MTR_VERSION=1
$ cat start_mtr98
perl mysql-test-run.pl --start-and-exit --valgrind --mysqld=--relay-log=slave-relay-bin --mysqld=--abort-slave-event-count=10 --mysqld=--log-queries-not-using-indexes --mysqld=--secure-file-priv= --mysqld=--max-allowed-packet=16Mb --mysqld=--loose-innodb-status-file=1 --mysqld=--master-retry-count=65535 --mysqld=--loose-debug-assert-if-crashed-table --mysqld=--loose-debug-assert-on-error --mysqld=--skip-name-resolve --vardir=/home/laurynas/percona/src/tmp8 --master_port=17001 --mysqld="--log-output=none" --mysqld="--sql_mode=ONLY_FULL_GROUP_BY" --mysqld="--innodb-max-bitmap-file-size=4095" --mysqld="--innodb-changed-pages-limit=-1" 1st

Nor with --mysqld=--aaa....aaa, neither in the start_mtr98, neither in -master.opt.

Code reading did not come up with anything.

[Laurynas Biveinis (laurynas-biveinis)]

Is this still current?

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-618