MySQL Bugs: #87935: Test sys_vars.myisam_data_pointer_size

Bug #87935	Test sys_vars.myisam_data_pointer_size_func too slow with sanitizers enabled
Submitted:	2 Oct 2017 6:50	Modified:	4 Oct 2017 2:37
Reporter:	Laurynas Biveinis (OCA)	Email Updates:
Status:	Open	Impact on me:	None
Category:	MySQL Server: Tests	Severity:	S7 (Test Cases)
Version:	8.0.3	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
On an otherwise idle Core i7, -DWITH_ASAN=ON -DWITH_UBSAN=ON:

$ ./mtr --debug-server myisam_data_pointer_size_func --testcase-timeout=9000
...
worker[1] Test still running: sys_vars.myisam_data_pointer_size_func
sys_vars.myisam_data_pointer_size_func   [ pass ]  1213125
...

Thus, this test is not able to complete on a reasonable CPU with default timeout on ASan/UBSan build

How to repeat:
See above

Suggested fix:
Create and use mysql-test/include/no_sanitizers_without_big.inc, similar to existing no_valgrind_without_big.inc?

Make the test smaller - it has a loop with 65536 repetitions?

Hello Laurynas,

Thank you for the report and feedback.
I'm not seeing this issue on even smaller box. Could you please confirm whether anything else required to trigger this issue?

Thanks,
Umesh

Big-box test results

Attachment: 87935_Bigbox.results (application/octet-stream, text), 266.17 KiB.

Tiny-box test results

Attachment: 87935_Smallbox.results (application/octet-stream, text), 268.74 KiB.

It could be that it is a specific compiler version that adds too much overhead for sanitizers. My results are on Ubuntu 17.04, compiled with GCC 6.3.0.

My full CMake args are -DBUILD_CONFIG=mysql_release -DWITH_DEBUG=ON -DWITH_ASAN=ON -DWITH_UBSAN=ON -DWITH_BOOST=~/mysql-boost -DDOWNLOAD_BOOST=ON -DENABLE_DOWNLOADS=ON -DWITH_PROTOBUF=system -DWITH_LZ4=system -DWITH_MECAB=system -DWITH_SSL=system -DWITH_ZLIB=system -DWITH_CURL=system

Tried on 17.04(Virtualbox), with exact cmake options(protobuf installed from source) provided by Laurynas, but still not seeing reported issue at my end. I'll try with fresh VM instance and give it a try again.

On my netbook this test is too slow with 8.0.11 even when non-ASAN build is used:

cmake . -DCMAKE_BUILD_TYPE=RelWithDebInfo -DBUILD_CONFIG=mysql_release -DFEATURE_SET=community -DWITH_EMBEDDED_SERVER=OFF -DCMAKE_INSTALL_PREFIX=/home/openxs/dbs/8.0 -DWITH_BOOST=/home/openxs/boost -DDOWNLOAD_BOOST=1  -DENABLE_DOWNLOADS=1 -DWITH_UNIT_TESTS=OFF

I get assertion 6 in the error log:

...
Thread 1 (Thread 0x7fd5c9ab4840 (LWP 21084)):
#0  0x00007fd5c96af611 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61
#1  0x0000000000d987dc in handle_fatal_signal (sig=6) at /home/openxs/git/mysql-server/sql/signal_handler.cc:249
#2  <signal handler called>
#3  0x00007fd5c7d55c9d in poll () at ../sysdeps/unix/syscall-template.S:81
#4  0x0000000000d90541 in poll (__timeout=-1, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/poll2.h:41
#5  Mysqld_socket_listener::listen_for_connection_event (this=0x432f8c0) at /home/openxs/git/mysql-server/sql/conn_handler/socket_connection.cc:739
#6  0x0000000000bc3820 in connection_event_loop (this=0x43505e0) at /home/openxs/git/mysql-server/sql/conn_handler/connection_acceptor.h:64
#7  mysqld_main (argc=67, argv=0x40cd6b8) at /home/openxs/git/mysql-server/sql/mysqld.cc:6352
#8  0x00007fd5c7c86f45 in __libc_start_main (main=0xb74ea0 <main(int, char**)>, argc=9, argv=0x7ffd345c6a28, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd345c6a18) at libc-start.c:287
#9  0x0000000000ba38e8 in _start ()

--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 1008 seconds executing testcases

Completed: Failed 1/1 tests, 0.00% were successful.

Failing test(s): sys_vars.myisam_data_pointer_size_func

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases
openxs@ao756:~/dbs/8.0/mysql-test$ cat var/log/mysqld.1.err
CURRENT_TEST: sys_vars.myisam_data_pointer_size_func
2018-04-25T10:54:25.591573Z 0 [Warning] [MY-010139] [Server] Changed limits: max_open_files: 1024 (requested 8161)
2018-04-25T10:54:25.591693Z 0 [Warning] [MY-010142] [Server] Changed limits: table_open_cache: 431 (requested 4000)
2018-04-25T10:54:25.854790Z 0 [Warning] [MY-010099] [Server] Insecure configuration for --secure-file-priv: Data directory is accessible through --secure-file-priv. Consider choosing a different directory.
2018-04-25T10:54:25.854831Z 0 [Warning] [MY-010101] [Server] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2018-04-25T10:54:25.854904Z 0 [System] [MY-010116] [Server] /home/openxs/dbs/8.0/bin/mysqld (mysqld 8.0.11) starting as process 21084
2018-04-25T10:54:28.463593Z 0 [Warning] [MY-010075] [Server] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 06a5c498-4877-11e8-ab70-f4b7e2133dbd.
2018-04-25T10:54:28.624457Z 0 [Warning] [MY-010068] [Server] CA certificate /home/openxs/dbs/8.0/mysql-test/std_data/cacert.pem is self signed.
2018-04-25T10:54:28.673071Z 0 [Warning] [MY-011071] [Server] unknown variable 'loose-debug-sync-timeout=600'
2018-04-25T10:54:28.710740Z 0 [System] [MY-010931] [Server] /home/openxs/dbs/8.0/bin/mysqld: ready for connections. Version: '8.0.11'  socket: '/home/openxs/dbs/8.0/mysql-test/var/tmp/mysqld.1.sock'  port: 13000  MySQL Community Server (GPL).
safe_process[21083]: Child process: 21084, aborted by signal: 6
11:09:29 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=3
max_threads=151
thread_count=2
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 67834 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x46000
/home/openxs/dbs/8.0/bin/mysqld(my_print_stacktrace(unsigned char*, unsigned long)+0x2e) [0x1bc641e]
/home/openxs/dbs/8.0/bin/mysqld(handle_fatal_signal+0x425) [0xd98765]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10330) [0x7fd5c96b2330]
/lib/x86_64-linux-gnu/libc.so.6(__poll+0x2d) [0x7fd5c7d55c9d]
/home/openxs/dbs/8.0/bin/mysqld(Mysqld_socket_listener::listen_for_connection_event()+0x41) [0xd90541]
/home/openxs/dbs/8.0/bin/mysqld(mysqld_main(int, char**)+0x4e10) [0xbc3820]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7fd5c7c86f45]
/home/openxs/dbs/8.0/bin/mysqld() [0xba38e8]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
safe_process[21083]: Child process: 21084, killed by signal: 6
openxs@ao756:~/dbs/8.0/mysql-test$