Bug #90633 innodb_fts.ngram_1 test fails (runs too long probably)
Submitted: 25 Apr 2018 16:27 Modified: 24 Oct 2018 10:00
Reporter: Valeriy Kravchuk Email Updates:
Status: Won't fix Impact on me:
None 
Category:MySQL Server: Tests Severity:S3 (Non-critical)
Version:8.0.11 OS:Ubuntu (14.04)
Assigned to: CPU Architecture:Any
Tags: innodb_fts.ngram_1, test

[25 Apr 2018 16:27] Valeriy Kravchuk
Description:
innodb_fts.ngram_1 test fails for me:

...
Spent 0.000 of 1006 seconds executing testcases

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

Failing test(s): innodb_fts.ngram_1

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: innodb_fts.ngram_1
2018-04-25T15:52:04.127213Z 0 [Warning] [MY-010139] [Server] Changed limits: max_open_files: 1024 (requested 8161)
2018-04-25T15:52:04.127348Z 0 [Warning] [MY-010142] [Server] Changed limits: table_open_cache: 431 (requested 4000)
2018-04-25T15:52:04.389684Z 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-25T15:52:04.389725Z 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-25T15:52:04.389797Z 0 [System] [MY-010116] [Server] /home/openxs/dbs/8.0/bin/mysqld (mysqld 8.0.11) starting as process 8050
2018-04-25T15:52:07.123911Z 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: 9b3d1296-48a0-11e8-adf4-f4b7e2133dbd.
2018-04-25T15:52:07.227567Z 0 [Warning] [MY-010068] [Server] CA certificate /home/openxs/dbs/8.0/mysql-test/std_data/cacert.pem is self signed.
2018-04-25T15:52:07.274674Z 0 [Warning] [MY-011071] [Server] unknown variable 'loose-debug-sync-timeout=600'
2018-04-25T15:52:07.312924Z 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[8049]: Child process: 8050, aborted by signal: 6
16:07:09 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=1
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) [0x7f82ffcca330]
/lib/x86_64-linux-gnu/libc.so.6(__poll+0x2d) [0x7f82fe36dc9d]
/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) [0x7f82fe29ef45]
/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[8049]: Child process: 8050, killed by signal: 6
openxs@ao756:~/dbs/8.0/mysql-test$

How to repeat:
Build MySQL 8.0.11 from GitHub source using the followi8ng cmake command line:

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

Run the test on slow machine:

./mtr innodb_fts.ngram_1

Suggested fix:
Maybe skip this test without --big-test option, or make it run faster?
[25 Apr 2018 23:21] MySQL Verification Team
Thank you for the bug report. I was able to repeat with 8.0.11 but not anymore with most recent source server, so I am closing as cannot repeat:

miguel@tikal:~/tmp/dbs/8.0/mysql-test $ ./mtr innodb_fts.ngram_1
Logging: ./mtr  innodb_fts.ngram_1
2018-04-25T22:56:24.461510Z 0 [System] [MY-010116] [Server] /home/miguel/tmp/dbs/8.0/bin/mysqld (mysqld 8.0.12) starting as process 4873
MySQL Version 8.0.12
Checking supported features...
 - SSL connections supported
Collecting tests...
Removing old var directory...
Creating var directory '/home/miguel/tmp/dbs/8.0/mysql-test/var'...
Installing system database...
Using parallel: 1

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

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb_fts.ngram_1                       [ fail ]
        Test ended at 2018-04-25 20:09:41

CURRENT_TEST: innodb_fts.ngram_1
--- /home/miguel/tmp/dbs/8.0/mysql-test/suite/innodb_fts/r/ngram_1.result       2018-04-08 09:44:49.000000000 +0300
+++ /home/miguel/tmp/dbs/8.0/mysql-test/var/log/ngram_1.reject  2018-04-26 02:09:40.898654221 +0300
@@ -95,7 +95,6 @@
-------------------------------------------------------------------------
miguel@tikal:~/build/2018APR18/mysql-8.0/mysql-test $ ./mtr innodb_fts.ngram_1
Logging: ./mtr  innodb_fts.ngram_1
2018-04-25T20:47:29.954221Z 0 [System] [MY-010116] [Server] /home/miguel/build/2018APR18/mysql-8.0/runtime_output_directory/mysqld (mysqld 8.0.12) starting as process 2654
MySQL Version 8.0.12
Checking supported features...
 - SSL connections supported
Collecting tests...
Removing old var directory...
Creating var directory '/home/miguel/build/2018APR18/mysql-8.0/mysql-test/var'...
Installing system database...
Using parallel: 1

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

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb_fts.ngram_1                       [ pass ]  751350
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 751.350 of 800 seconds executing testcases

Completed: All 1 tests were successful.
[25 Apr 2018 23:26] MySQL Verification Team
Sorry I confused with the test which failed was 8.0.11 but really was the same 8.0.12 but compiled as reporter indicated, so corrected as Verified:

miguel@tikal:~/tmp/dbs/8.0/mysql-test $ ./mtr innodb_fts.ngram_1
Logging: ./mtr  innodb_fts.ngram_1
2018-04-25T22:56:24.461510Z 0 [System] [MY-010116] [Server] /home/miguel/tmp/dbs/8.0/bin/mysqld (mysqld 8.0.12) starting as process 4873
MySQL Version 8.0.12
Checking supported features...
 - SSL connections supported
Collecting tests...
Removing old var directory...
Creating var directory '/home/miguel/tmp/dbs/8.0/mysql-test/var'...
Installing system database...
Using parallel: 1

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

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb_fts.ngram_1                       [ fail ]
        Test ended at 2018-04-25 20:09:41

CURRENT_TEST: innodb_fts.ngram_1
--- /home/miguel/tmp/dbs/8.0/mysql-test/suite/innodb_fts/r/ngram_1.result       2018-04-08 09:44:49.000000000 +0300
+++ /home/miguel/tmp/dbs/8.0/mysql-test/var/log/ngram_1.reject  2018-04-26 02:09:40.898654221 +0300
@@ -95,7 +95,6 @@
 SELECT * FROM articles_1 WHERE
[24 Oct 2018 10:00] Erlend Dahl
It runs in 77 seconds on my local machine:

[100%] innodb_fts.ngram_1 [ pass ]  77243

Solaris takes quite a while more time:

[ 58%] innodb_fts.ngram_1 w9  [ pass ]  131269

There really isn't any reason to tweak the testsuite towards running properly on weak platforms. Please use the --testcase-timeout argument to MTR instead.