[MDEV-20372] thread_pool_info fails randomly in 10.5 Created: 2019-08-18  Updated: 2020-10-14  Resolved: 2020-05-28

Status: Closed
Project: MariaDB Server
Component/s: N/A
Affects Version/s: 10.5
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Michael Widenius Assignee: Vladislav Vaintroub
Resolution: Fixed Votes: 1
Labels: None


 Description   

https://buildbot.askmonty.org/buildbot/reports/cross_reference with test "thread_pool_info" shows a lot of failures, mostly in 10.5

Example:
https://buildbot.askmonty.org/buildbot/builders/kvm-deb-bionic-amd64/builds/2721

main.thread_pool_info w1 [ fail ]
Test ended at 2019-08-16 10:29:34

CURRENT_TEST: main.thread_pool_info
— /usr/share/mysql/mysql-test/main/thread_pool_info.result 2019-08-16 07:40:14.000000000 -0400
+++ /dev/shm/var/1/log/thread_pool_info.reject 2019-08-16 10:29:34.265336935 -0400
@@ -55,7 +55,7 @@
FLUSH THREAD_POOL_STATS;
SELECT SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER) FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER)
-1
+0
SELECT SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER) FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)
2



 Comments   
Comment by Marko Mäkelä [ 2020-02-26 ]

Slightly different result difference:

10.5 9894751a2a61ef952ac6ac556fd683e53fc150e2

CURRENT_TEST: main.thread_pool_info
--- /mariadb/10.5/mysql-test/main/thread_pool_info.result	2019-08-21 17:49:42.984891187 +0300
+++ /mariadb/10.5/mysql-test/main/thread_pool_info.reject	2020-02-26 14:57:03.629456121 +0200
@@ -58,7 +58,7 @@
 1
 SELECT SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER) FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
 SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)
-2
+3
 DESC INFORMATION_SCHEMA.THREAD_POOL_WAITS;
 Field	Type	Null	Key	Default	Extra
 REASON	varchar(16)	NO			

At least one InnoDB test was previously run on the same worker. Could it be that InnoDB purge tasks (for InnoDB data dictionary tables) are affecting this?

Comment by Otto Kekäläinen [ 2020-03-27 ]

This is also affecting Connector C builds and preventing https://github.com/mariadb-corporation/mariadb-connector-c/pull/130 from being merged "cleanly".

Issue has been open since 2019 August. Ping julien.fritsch

Comment by Otto Kekäläinen [ 2020-03-27 ]

Every single developer who has ever pushed on a 10.5 branch has surely seen this error has it happens all the time for the past several months.

https://travis-ci.org/github/MariaDB/server/jobs/667498025

Arch: ppc64le
Compiler: gcc C++
CC_VERSION=7 TYPE=RelWithDebInfo MYSQL_TEST_SUITES=main

main.thread_pool_info                    w3 [ fail ]
        Test ended at 2020-03-27 08:35:53
CURRENT_TEST: main.thread_pool_info
--- /home/travis/build/MariaDB/server/mysql-test/main/thread_pool_info.result	2020-03-27 08:21:25.249586421 +0000
+++ /home/travis/build/MariaDB/server/mysql-test/main/thread_pool_info.reject	2020-03-27 08:35:53.623673035 +0000
@@ -55,7 +55,7 @@
 FLUSH THREAD_POOL_STATS;
 SELECT SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER)  FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
 SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER)
-1
+0
 SELECT SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER) FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
 SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)
 2

https://travis-ci.org/github/MariaDB/server/jobs/667498027

Arch: AMD64
Compiler: clang C++
CC_VERSION=8 TYPE=RelWithDebInfo MYSQL_TEST_SUITES=main

main.thread_pool_info                    w1 [ fail ]
        Test ended at 2020-03-27 08:51:45
CURRENT_TEST: main.thread_pool_info
mysqltest: At line 30: query 'FLUSH THREAD_POOL_STATS' failed: 2013: Lost connection to MySQL server during query
The result from queries just before the failure was:
< snip >
DESC INFORMATION_SCHEMA.THREAD_POOL_STATS;
Field	Type	Null	Key	Default	Extra
GROUP_ID	int(6)	NO		0	
THREAD_CREATIONS	bigint(19)	NO		0	
THREAD_CREATIONS_DUE_TO_STALL	bigint(19)	NO		0	
WAKES	bigint(19)	NO		0	
WAKES_DUE_TO_STALL	bigint(19)	NO		0	
THROTTLES	bigint(19)	NO		0	
STALLS	bigint(19)	NO		0	
POLLS_BY_LISTENER	bigint(19)	NO		0	
POLLS_BY_WORKER	bigint(19)	NO		0	
DEQUEUES_BY_LISTENER	bigint(19)	NO		0	
DEQUEUES_BY_WORKER	bigint(19)	NO		0	
SELECT SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER) > 0 FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER) > 0
1
SELECT SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER) > 0 FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER) > 0
1
FLUSH THREAD_POOL_STATS;
More results from queries before failure can be found in /home/travis/build/MariaDB/server/mysql-test/var/1/log/thread_pool_info.log
Server [mysqld.1 - pid: 30157, winpid: 30157, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2020-03-27  8:51:44 0 [Note] /home/travis/build/MariaDB/server/sql/mysqld (mysqld 10.5.3-MariaDB-log) starting as process 30158 ...
2020-03-27  8:51:44 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32182)
2020-03-27  8:51:44 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
2020-03-27  8:51:44 0 [Note] Plugin 'InnoDB' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'partition' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'SEQUENCE' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_BUFFER_PAGE' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_TRX' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_CMP_PER_INDEX' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_METRICS' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_CMP' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_LOCKS' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_CMPMEM' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'user_variables' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2020-03-27  8:51:44 0 [Note] Plugin 'unix_socket' is disabled.
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-feedback-debug-interval=60'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown option '--loose-pam-debug'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown option '--loose-enable-performance-schema'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-accounts-size=100'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-digests-size=200'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-hosts-size=100'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-users-size=100'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-mutex-instances=5000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-rwlock-instances=5000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-cond-instances=1000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-file-instances=10000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-socket-instances=1000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-table-instances=500'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-table-lock-stat=500'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-index-stat=5000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-table-handles=1000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-prepared-statements-instances=100'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-program-instances=5000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-setup-actors-size=100'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-setup-objects-size=100'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-events-waits-history-size=10'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-events-waits-history-long-size=10000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-events-stages-history-size=10'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-events-stages-history-long-size=1000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-events-statements-history-size=10'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-events-statements-history-long-size=1000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-events-transactions-history-size=10'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-events-transactions-history-long-size=1000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-thread-instances=200'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-session-connect-attrs-size=2048'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-max-metadata-locks=10000'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-instrument=%=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-stages-current=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-stages-history=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-stages-history-long=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-statements-current=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-statements-history=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-statements-history-long=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-transactions-current=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-transactions-history=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-transactions-history-long=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-waits-current=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-waits-history=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-events-waits-history-long=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-global-instrumentation=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-performance-schema-consumer-thread-instrumentation=ON'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown option '--loose-aria'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown option '--loose-enable-performance-schema'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-thread-pool-mode=generic'
2020-03-27  8:51:44 0 [Warning] /home/travis/build/MariaDB/server/sql/mysqld: unknown variable 'loose-debug-sync-timeout=300'
2020-03-27  8:51:44 0 [Note] Server socket created on IP: '127.0.0.1'.
2020-03-27  8:51:44 0 [Note] Reading of all Master_info entries succeeded
2020-03-27  8:51:44 0 [Note] Added new Master_info '' to hash table
2020-03-27  8:51:44 0 [Note] /home/travis/build/MariaDB/server/sql/mysqld: ready for connections.
Version: '10.5.3-MariaDB-log'  socket: '/home/travis/build/MariaDB/server/mysql-test/var/tmp/1/mysqld.1.sock'  port: 16000  Source distribution
200327  8:51:44 [ERROR] mysqld got signal 11 ;
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.
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
Server version: 10.5.3-MariaDB-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=65537
thread_count=2
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 25170973 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x7f17a4000a98
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 = 0x7f17bd66adf0 thread_stack 0x49000
mysys/stacktrace.c:306(my_print_stacktrace)[0x561562bafe69]
sql/signal_handler.cc:206(handle_fatal_signal)[0x561562767090]
??:0(__restore_rt)[0x7f17c1972390]
sql/thread_pool_info.cc:214(stats_reset_table())[0x561562c23c39]
sql/sql_reload.cc:424(reload_acl_and_cache(THD*, unsigned long long, TABLE_LIST*, int*))[0x56156268da5e]
??:0(mysql_execute_command(THD*))[0x56156259696e]
sql/sql_class.h:2433(THD::enter_stage(PSI_stage_info_none const*, char const*, char const*, unsigned int))[0x56156258fefd]
sql/sql_parse.cc:1839(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x56156258d6c9]
sql/sql_parse.cc:1358(do_command(THD*))[0x5615625903b1]
sql/threadpool_common.cc:357(threadpool_process_request(THD*))[0x56156273b113]
sql/threadpool_generic.cc:1501(worker_main(void*))[0x5615628e4e6e]
??:0(start_thread)[0x7f17c19686ba]
??:0(clone)[0x7f17bf3d641d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7f17a4010270): FLUSH THREAD_POOL_STATS
Connection ID (thread ID): 4
Status: NOT_KILLED
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on,not_null_range_scan=off
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...
Working directory at /home/travis/build/MariaDB/server/mysql-test/var/1/mysqld.1/data
Resource Limits:
Limit                     Soft Limit           Hard Limit           Units     
Max cpu time              unlimited            unlimited            seconds   
Max file size             unlimited            unlimited            bytes     
Max data size             unlimited            unlimited            bytes     
Max stack size            8388608              unlimited            bytes     
Max core file size        unlimited            unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             31806                31806                processes 
Max open files            1024                 1024                 files     
Max locked memory         65536                65536                bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       31806                31806                signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        
Core pattern: |/usr/share/apport/apport %p %s %c %d %P
----------SERVER LOG END-------------
 - found 'core' (0/5)
Trying 'dbx' to get a backtrace
Trying 'gdb' to get a backtrace from coredump /home/travis/build/MariaDB/server/mysql-test/var/1/log/main.thread_pool_info/mysqld.1/data/core
Core generated by '/home/travis/build/MariaDB/server/sql/mysqld'
Output from gdb follows. The first stack trace is from the failing thread.
The following stack traces are from all threads (so the failing one is
duplicated).
--------------------------
warning: core file may not match specified executable file.
[New LWP 30196]
[New LWP 30166]
[New LWP 30158]
[New LWP 30168]
[New LWP 30170]
[New LWP 30169]
[New LWP 30171]
[New LWP 30189]
[New LWP 30195]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/home/travis/build/MariaDB/server/sql/mysqld --defaults-group-suffix=.1 --defau'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007f17c196f59f in pthread_kill () from /lib/x86_64-linux-gnu/libpthread.so.0
[Current thread is 1 (Thread 0x7f17bd66b700 (LWP 30196))]
#0  0x00007f17c196f59f in pthread_kill () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x0000561562767387 in handle_fatal_signal (sig=<optimized out>) at signal_handler.cc:325
#2  <signal handler called>
#3  stats_reset_table () at thread_pool_info.cc:214
#4  0x000056156268da5e in reload_acl_and_cache (thd=0x7f17a4000a98, options=<optimized out>, tables=<optimized out>, write_to_binlog=<optimized out>) at sql_reload.cc:424
#5  0x000056156259696e in mysql_execute_command (thd=0x7f17a4000a98) at sql_parse.cc:5382
#6  0x000056156258fefd in mysql_parse (thd=0x7f17a4000a98, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at sql_parse.cc:7953
#7  0x000056156258d6c9 in dispatch_command (command=COM_QUERY, thd=0x7f17a4000a98, packet=0x7f17a4007d49 "FLUSH THREAD_POOL_STATS", packet_length=2751529584, is_com_multi=<optimized out>, is_next_command=<optimized out>) at sql_parse.cc:1839
#8  0x00005615625903b1 in do_command (thd=0x7f17a4000a98) at sql_parse.cc:1358
#9  0x000056156273b113 in threadpool_process_request (thd=0x7f17a4000a98) at threadpool_common.cc:357
#10 tp_callback (c=0x5615656b5a60) at threadpool_common.cc:196
#11 0x00005615628e4e6e in worker_main (param=0x5615656aa718) at threadpool_generic.cc:1506
#12 0x00007f17c19686ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#13 0x00007f17bf3d641d in clone () from /lib/x86_64-linux-gnu/libc.so.6
Thread 9 (Thread 0x7f17bd6b5700 (LWP 30195)):
#0  0x00007f17c196e709 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00005615628e3c55 in inline_mysql_cond_timedwait (that=<optimized out>, mutex=<optimized out>, abstime=<optimized out>) at /home/travis/build/MariaDB/server/include/mysql/psi/mysql_thread.h:1268
#2  get_event (current_thread=0x7f17bd6b4e48, thread_group=0x5615656aa718, abstime=0x7f17bd6b4e38) at threadpool_generic.cc:1193
#3  0x00005615628e4eb8 in worker_main (param=0x5615656aa718) at threadpool_generic.cc:1502
#4  0x00007f17c19686ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#5  0x00007f17bf3d641d in clone () from /lib/x86_64-linux-gnu/libc.so.6
Thread 8 (Thread 0x7f17bd6ff700 (LWP 30189)):
#0  0x00007f17bf3d6a13 in epoll_wait () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00005615628e3d24 in io_poll_wait (pollfd=12, native_events=0x656b5a6000002011, maxevents=1024, timeout_ms=-1) at threadpool_generic.cc:224
#2  listener (current_thread=<optimized out>, thread_group=<optimized out>) at threadpool_generic.cc:686
#3  get_event (current_thread=0x7f17bd6fee48, thread_group=0x5615656aa818, abstime=<optimized out>) at threadpool_generic.cc:1148
#4  0x00005615628e4eb8 in worker_main (param=0x5615656aa818) at threadpool_generic.cc:1502
#5  0x00007f17c19686ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#6  0x00007f17bf3d641d in clone () from /lib/x86_64-linux-gnu/libc.so.6
Thread 7 (Thread 0x7f17bd749700 (LWP 30171)):
#0  0x00007f17c196e360 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00005615624f025b in inline_mysql_cond_wait (that=0x5615635c15b0 <COND_slave_background>, mutex=0x5615635c3fa0 <LOCK_slave_background>) at /home/travis/build/MariaDB/server/include/mysql/psi/mysql_thread.h:1231
#2  handle_slave_background (arg=<optimized out>) at slave.cc:525
#3  0x00007f17c19686ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#4  0x00007f17bf3d641d in clone () from /lib/x86_64-linux-gnu/libc.so.6
Thread 6 (Thread 0x7f17bdf94700 (LWP 30169)):
#0  0x00007f17c196e709 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00005615628e507a in inline_mysql_cond_timedwait (that=0x5615635f7e88 <pool_timer+48>, mutex=0x5615635f7e58 <pool_timer>, abstime=0x5e7dbea0) at /home/travis/build/MariaDB/server/include/mysql/psi/mysql_thread.h:1268
#2  timer_thread (param=0x5615635f7e58 <pool_timer>) at threadpool_generic.cc:529
#3  0x00007f17c19686ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#4  0x00007f17bf3d641d in clone () from /lib/x86_64-linux-gnu/libc.so.6
Thread 5 (Thread 0x7f17bd793700 (LWP 30170)):
#0  0x00007f17bf305b26 in sigwaitinfo () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00005615624d96fb in my_sigwait (set=0x86005, sig=<optimized out>, code=<optimized out>) at /home/travis/build/MariaDB/server/include/my_pthread.h:198
#2  signal_hand (arg=<optimized out>) at mysqld.cc:3087
#3  0x00007f17c19686ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#4  0x00007f17bf3d641d in clone () from /lib/x86_64-linux-gnu/libc.so.6
Thread 4 (Thread 0x7f17be795700 (LWP 30168)):
#0  0x00007f17c196e709 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x000056156290ec2a in inline_mysql_cond_timedwait (that=0x561563df91f4 <COND_checkpoint+4>, mutex=0x189, abstime=0x7f17be794e40) at /home/travis/build/MariaDB/server/include/mysql/psi/mysql_thread.h:1268
#2  my_service_thread_sleep (control=0x56156353fa30 <checkpoint_control>, sleep_time=29000000000) at ma_servicethread.c:115
#3  0x0000561562908495 in ma_checkpoint_background (arg=<optimized out>) at ma_checkpoint.c:707
#4  0x00007f17c19686ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#5  0x00007f17bf3d641d in clone () from /lib/x86_64-linux-gnu/libc.so.6
Thread 3 (Thread 0x7f17c1d88780 (LWP 30158)):
#0  0x00007f17bf3ca74d in poll () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00005615624de0a0 in handle_connections_sockets () at mysqld.cc:6308
#2  0x00005615624dcb0f in mysqld_main (argc=<optimized out>, argv=<optimized out>) at mysqld.cc:5770
#3  0x00007f17bf2ef830 in __libc_start_main () from /lib/x86_64-linux-gnu/libc.so.6
#4  0x00005615624d79c9 in _start ()
Thread 2 (Thread 0x7f17c1da2700 (LWP 30166)):
#0  0x00007f17c196e709 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x0000561562bb3174 in inline_mysql_cond_timedwait (that=0x561563e57eb0 <COND_timer>, mutex=0x561563e57e80 <LOCK_timer>, abstime=0x7f17c1da1e90) at /home/travis/build/MariaDB/server/include/mysql/psi/mysql_thread.h:1268
#2  timer_handler (arg=<optimized out>) at thr_timer.c:321
#3  0x00007f17c19686ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#4  0x00007f17bf3d641d in clone () from /lib/x86_64-linux-gnu/libc.so.6
Thread 1 (Thread 0x7f17bd66b700 (LWP 30196)):
#0  0x00007f17c196f59f in pthread_kill () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x0000561562767387 in handle_fatal_signal (sig=<optimized out>) at signal_handler.cc:325
#2  <signal handler called>
#3  stats_reset_table () at thread_pool_info.cc:214
#4  0x000056156268da5e in reload_acl_and_cache (thd=0x7f17a4000a98, options=<optimized out>, tables=<optimized out>, write_to_binlog=<optimized out>) at sql_reload.cc:424
#5  0x000056156259696e in mysql_execute_command (thd=0x7f17a4000a98) at sql_parse.cc:5382
#6  0x000056156258fefd in mysql_parse (thd=0x7f17a4000a98, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at sql_parse.cc:7953
#7  0x000056156258d6c9 in dispatch_command (command=COM_QUERY, thd=0x7f17a4000a98, packet=0x7f17a4007d49 "FLUSH THREAD_POOL_STATS", packet_length=2751529584, is_com_multi=<optimized out>, is_next_command=<optimized out>) at sql_parse.cc:1839
#8  0x00005615625903b1 in do_command (thd=0x7f17a4000a98) at sql_parse.cc:1358
#9  0x000056156273b113 in threadpool_process_request (thd=0x7f17a4000a98) at threadpool_common.cc:357
#10 tp_callback (c=0x5615656b5a60) at threadpool_common.cc:196
#11 0x00005615628e4e6e in worker_main (param=0x5615656aa718) at threadpool_generic.cc:1506
#12 0x00007f17c19686ba in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#13 0x00007f17bf3d641d in clone () from /lib/x86_64-linux-gnu/libc.so.6
Compressed file /home/travis/build/MariaDB/server/mysql-test/var/1/log/main.thread_pool_info/mysqld.1/data/core
 - saving '/home/travis/build/MariaDB/server/mysql-test/var/1/log/main.thread_pool_info/' to '/home/travis/build/MariaDB/server/mysql-test/var/log/main.thread_pool_info/'
main.lowercase_mixed_tmpdir              w3 [ pass ]     15
main.partition_ucs2                      w2 [ pass ]      2
***Warnings generated in error logs during shutdown after running tests: main.thread_pool_info
200327  8:51:44 [ERROR] mysqld got signal 11 ;
Attempting backtrace. You can use the following information to find out

Comment by Otto Kekäläinen [ 2020-03-27 ]

https://buildbot.mariadb.org/#/builders/35/builds/1146

aarch64-debian-10

main.thread_pool_info                    w1 [ fail ]
        Test ended at 2020-03-27 13:27:26
 
CURRENT_TEST: main.thread_pool_info
--- /buildbot/aarch64-debian-10/build/mysql-test/main/thread_pool_info.result	2020-03-26 23:57:52.000000000 +0000
+++ /buildbot/aarch64-debian-10/build/mysql-test/main/thread_pool_info.reject	2020-03-27 13:27:26.252277372 +0000
@@ -55,7 +55,7 @@
 FLUSH THREAD_POOL_STATS;
 SELECT SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER)  FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
 SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER)
-1
+0
 SELECT SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER) FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
 SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)
 2

Comment by Otto Kekäläinen [ 2020-03-28 ]

Seems this happens frequently or always on certain platforms, and sporadically on others.

https://travis-ci.org/github/ottok/mariadb/jobs/668010227
Arm64
Arch: Compiler: gcc C++
CC_VERSION=7 TYPE=RelWithDebInfo MYSQL_TEST_SUITES=main

main.thread_pool_info                    w4 [ fail ]
        Test ended at 2020-03-28 10:18:02
CURRENT_TEST: main.thread_pool_info
--- /home/travis/build/ottok/mariadb/mysql-test/main/thread_pool_info.result	2020-03-28 10:08:48.596376650 +0000
+++ /home/travis/build/ottok/mariadb/mysql-test/main/thread_pool_info.reject	2020-03-28 10:18:01.822896243 +0000
@@ -58,7 +58,7 @@
 1
 SELECT SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER) FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
 SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)
-2
+3
 DESC INFORMATION_SCHEMA.THREAD_POOL_WAITS;
 Field	Type	Null	Key	Default	Extra
 REASON	varchar(16)	NO		

Comment by Otto Kekäläinen [ 2020-04-23 ]

Temporarily disabled in https://github.com/MariaDB/server/commit/6f0b621caf76cf636771cab2e78b6e1846b31c78 - we can't have this keeping the CI red permanently, that halts all other quality assurance / testing work. Please fix and re-enable when you have a chance.

Comment by Daniel Black [ 2020-05-09 ]

Looking at why clang - power results with a slightly modified test. This is on a POWER8/ubutu-18.04:

clang6,7,8

CURRENT_TEST: main.thread_pool_info
--- /home/dan/mariadb-server-not-worktree/mysql-test/main/thread_pool_info.result	2020-05-09 17:51:48.327393084 +1000
+++ /home/dan/mariadb-server-not-worktree/mysql-test/main/thread_pool_info.reject	2020-05-09 18:32:43.534875500 +1000
@@ -56,9 +56,9 @@
 SELECT SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER)  FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
 SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER)
 1
-SELECT SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)  BETWEEN 2 AND 3 FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
-SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)  BETWEEN 2 AND 3
-1
+SELECT SUM(POLLS_BY_LISTENER),SUM(POLLS_BY_WORKER) FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
+SUM(POLLS_BY_LISTENER)	SUM(POLLS_BY_WORKER)
+23	0

clang9+

CURRENT_TEST: main.thread_pool_info
--- /home/dan/mariadb-server-not-worktree/mysql-test/main/thread_pool_info.result	2020-05-09 17:51:48.327393084 +1000
+++ /home/dan/mariadb-server-not-worktree/mysql-test/main/thread_pool_info.reject	2020-05-09 18:34:09.569118955 +1000
@@ -56,9 +56,9 @@
 SELECT SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER)  FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
 SUM(DEQUEUES_BY_LISTENER+DEQUEUES_BY_WORKER)
 1
-SELECT SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)  BETWEEN 2 AND 3 FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
-SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)  BETWEEN 2 AND 3
-1
+SELECT SUM(POLLS_BY_LISTENER),SUM(POLLS_BY_WORKER) FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
+SUM(POLLS_BY_LISTENER)	SUM(POLLS_BY_WORKER)
+2	0

This is consistent with all the clang results on buildbot. TODO need to work out why clang678 generate different code.

Comment by Otto Kekäläinen [ 2020-05-15 ]

This is still happening and is annoying, since it leads to failure reports on pull requests:

e.g.
https://buildbot.mariadb.org/#/builders/38/builds/742/steps/8/logs/stdio
https://buildbot.mariadb.org/#/builders/40/builds/1414/steps/8/logs/stdio

main.thread_pool_info                    w6 [ fail ]
        Test ended at 2020-05-14 14:47:02
CURRENT_TEST: main.thread_pool_info
--- /buildbot/pc9-clang6-ubuntu-1804/build/mysql-test/main/thread_pool_info.result	2020-05-14 14:33:37.000000000 +0000
+++ /buildbot/pc9-clang6-ubuntu-1804/build/mysql-test/main/thread_pool_info.reject	2020-05-14 14:47:02.339181384 +0000
@@ -58,7 +58,7 @@
 1
 SELECT SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)  BETWEEN 2 AND 3 FROM INFORMATION_SCHEMA.THREAD_POOL_STATS;
 SUM(POLLS_BY_LISTENER+POLLS_BY_WORKER)  BETWEEN 2 AND 3
-1
+0
 DESC INFORMATION_SCHEMA.THREAD_POOL_WAITS;
 Field	Type	Null	Key	Default	Extra
 REASON	varchar(16)	NO			
mysqltest: Result content mismatch

Comment by Vladislav Vaintroub [ 2020-05-15 ]

Does not happen for me.

Comment by Otto Kekäläinen [ 2020-05-15 ]

What do you mean does not happen to you? You mean that when you push your branches on Github and CI runs, it does not yield any errors?

Comment by Vladislav Vaintroub [ 2020-05-15 ]

I mean, this does not happen in real buildbot

Comment by Otto Kekäläinen [ 2020-05-15 ]

So buildbot.mariadb.org or Travis-CI or other systems don't matter, is
that what you imply here?

Comment by Vladislav Vaintroub [ 2020-05-15 ]

Yes, the new "experimental" buildbot is something, that I never, ever look into, as long as it is experimental. It had been in experimental state for what, 3 years?

Comment by Otto Kekäläinen [ 2020-05-28 ]

This issue is still open. I think it can be closed if somebody can point out that latest buildbot.mariadb.org builds that used to fail on the test now pass and everything is OK.

Comment by Vladislav Vaintroub [ 2020-05-28 ]

Otto, you would be that somebody . I have no idea what used to fail, it does not have cross-reference.
That
http://buildbot.askmonty.org/buildbot/reports/cross_reference

is cross-reference.

That is the list of the failures for this specific test shorturl.at/dhzX5

Comment by Otto Kekäläinen [ 2020-05-28 ]

Could vladbogo perhaps help here a bit on how one can check if buildbot.mariadb.org branch 10.5 is still failing for main.thread_pool_info as Wlad might benefit from learning on how to do it?

Comment by Vladislav Vaintroub [ 2020-05-28 ]

Maybe we should stop abusing the bug report, and somebody just creates a good documentation for the experimental buildbot that is run by the foundation, and announces the availability of the documentation on the mailing list.

Comment by Vlad Bogolin [ 2020-05-28 ]

otto cross reference is not available at this point, so that cannot be easily achieved.

Comment by Otto Kekäläinen [ 2020-05-28 ]

I did not find the page that is an overview of branch 10.5, but via a recent commit I found this view: https://buildbot.mariadb.org/#/changes/52636

It confirms that the issue I reported on May 15th does not exists anymore and the builder passes.

After that there was multiple fix commits to threadpool, so seems one of those fixed this issue for good and it is OK to close this bug report.

$ git log --format="%Cgreen%ci%Creset %aE %s" --since=2020-05-01 sql/threadpool*
2020-05-25 14:54:11 +0200 wlad@mariadb.com MDEV-22696 TP_pool_generic::set_pool_size logic so that it marks each connection to change group before the next socket read.
2020-05-25 14:54:11 +0200 wlad@mariadb.com MDEV-22696 Threadpool : make sure thd->event_scheduler.data does not change as long as THD is in server_threads.
2020-05-25 14:54:00 +0200 wlad@mariadb.com Threadpool - support changing group on Windows with generic thread pool
2020-05-23 12:29:10 +0300 monty@mariadb.org Change THD->transaction to a pointer to enable multiple transactions
2020-05-15 16:29:06 +0200 wlad@mariadb.com MDEV-22578 thread_pool_info crashes with clang6, using SSE instructions on unaligned memory

Comment by Vladislav Vaintroub [ 2020-05-28 ]

"MDEV-22578 thread_pool_info crashes with clang6, using SSE instructions on unaligned memory" is fix for a regression that was introduced in MDEV-5205 many moons ago , which resulted in a very much reproducible crash with optimized build on clang6.

It is possible that declared alignment on a structure, which is not given due to my_malloc() could cause other problems if compiler takes alignment seriously.

Nothing else has even a remote relation with that bug, and are small performance tweaks, some windows fix, and something monty needed. Impressive detective work though.

Comment by Otto Kekäläinen [ 2020-10-13 ]

Looking at recent Travis-CI jobs at https://travis-ci.org/github/MariaDB/server/branches I did not see any jobs failing on this test, so I hereby confirm that this issue is fixed.

Thanks!

Generated at Thu Feb 08 08:58:58 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.