Details
-
Bug
-
Status: Stalled (View Workflow)
-
Minor
-
Resolution: Unresolved
-
10.5
-
None
Description
LD_LIBRARY_PATH=<path to MSAN libs> perl mysql-test-run.pl perfschema.short_option_1
|
|
10.5 1ac0bce36e |
***Warnings generated in error logs during shutdown after running tests: perfschema.short_option_1
|
Version: '10.5.17-MariaDB-debug-log' socket: '/home/jenkins/10.5/mysql-test/var/tmp/mysqld.1.sock' port: 16000 Source distribution
|
2022-09-11 1:02:33 0 [ERROR] Error in accept: Invalid argument
|
2022-09-11 1:02:33 0 [Note] /home/jenkins/10.5/sql/mariadbd (initiated by: unknown): Normal shutdown
|
2022-09-11 1:02:33 0 [Note] Event Scheduler: Purging the queue. 0 events
|
2022-09-11 1:02:33 0 [Note] Debug sync points hit: 1941
|
2022-09-11 1:02:33 0 [Note] Debug sync points executed: 0
|
2022-09-11 1:02:33 0 [Note] Debug sync points max active per thread: 0
|
2022-09-11 1:02:33 0 [Note] /home/jenkins/10.5/sql/mariadbd: Shutdown complete
|
|
|
|
|
User time 0.26, System time 0.18
|
Maximum resident set size 351552, Integral resident set size 0
|
Non-physical pagefaults 112789, Physical pagefaults 0, Swaps 0
|
Blocks in 0 out 912, Messages in 0 out 0, Signals 0
|
Voluntary context switches 64, Involuntary context switches 2
|
My build was built with
cmake -DPLUGIN_ROCKSDB=NO -DPLUGIN_MROONGA=NO -DPLUGIN_SPHINX=NO -DPLUGIN_OQGRAPH=NO -DPLUGIN_FEDERATED=NO -DPLUGIN_FEDERATEDX=NO -DPLUGIN_SPIDER=NO -DWITH_MARIBACKUP=OFF -DPLUGIN_CONNECT=NO -DPLUGIN_EXAMPLE=NO -DPLUGIN_TOKUDB=NO -DCMAKE_BUILD_TYPE=Debug -DMYSQL_MAINTAINER_MODE=OFF -DWITH_EMBEDDED_SERVER=OFF -DWITH_SAFEMALLOC=OFF -DWITH_ZLIB=bundled -DWITH_SSL=bundled -DWITH_PCRE=bundled -DCMAKE_DISABLE_FIND_PACKAGE_URING=1 -DCMAKE_DISABLE_FIND_PACKAGE_LIBAIO=1 -DHAVE_LIBAIO_H=0 '-DCMAKE_C_FLAGS=-O2 -Wno-unused-command-line-argument -fdebug-macro' '-DCMAKE_CXX_FLAGS=-stdlib=libc++ -O2 -Wno-unused-command-line-argument -fdebug-macro' -DCMAKE_C_COMPILER=clang-12 -DCMAKE_CXX_COMPILER=clang++-12 -DPLUGIN_SPIDER=NO -DWITH_MSAN=ON -DMAX_INDEXES=128 -G Ninja .
|
but it's also happening in the Foundation buildbot.
I only observed it on 10.5, not sure about the buildbot (since it's a post-test failure, it's not stored in the cross-reference).
The effect is deterministic at least on 10.5. It started happening after this patch
commit 122742897b47a19c85b1a5e9932ab3a8c2a4134e
|
Author: Sergei Golubchik
|
Date: Thu Jun 23 12:59:31 2022 +0200
|
|
|
my_safe_process: try to kill the process softly first
|
|
first SIGTERM and if the process didn't die in 10 seconds, SIGKILL it.
|
|
This allows various tools like `rr`, `gcov`, `gprof`, etc to flush
|
their data to disk properly
|
I can't tell whether the change introduced a bogus failure or revealed a previously hidden problem.
Attachments
Issue Links
- relates to
-
-
- Open
-
Activity
Quick update:
- I was able to repeat it on my home system with --repeat=10 and WITHOUT valgrind!
It will still hang ! - In other words, this test has nothing to do with valgrind and we can remove the disabling of valgrind here.
Still need to fix the bug that was caused by Serg's patch.
We should probably disable the error in 'accept' if we are under shutdown.
This issue was caused by the short_option_1-master.opt file that had the option -T12, which means (among other things) to use blocking for sockets. This was supported up to MariaDB 10.4, but not in 10.5 where we have removed the code that changes blocking sockets to non blocking in case of errors.
Fix for 10.5 will be pushed shortly
Automated message:
----------------------------
Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.
Automated message:
----------------------------
Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.
Here is an excerpt from a server error log where Valgrind’s memcheck tool was sent SIGQUIT to resolve a hang during the test:
10.6 8872d2ee71cc65826909f6a64413ee46d1c5218d
2022-10-12 8:54:29 0 [Note] /buildbot/amd64-ubuntu-1804-valgrind/build/sql/mariadbd: Shutdown completeCURRENT_TEST: perfschema.short_option_1$ valgrind --tool=memcheck --show-reachable=yes --leak-check=yes --num-callers=16 --quiet --suppressions=/buildbot/amd64-ubuntu-1804-valgrind/build/mysql-test/valgrind.supp --leak-check=summary --gen-suppressions=yes --num-callers=10 /buildbot/amd64-ubuntu-1804-valgrind/build/sql/mariadbd --defaults-group-suffix=.1 --defaults-file=/buildbot/amd64-ubuntu-1804-valgrind/build/mysql-test/var/21/my.cnf --log-output=file -a -Cutf8 --collation-server=utf8_bin -T12 -W2 --core-file --loose-debug-sync-timeout=300 --loose-debug-gdb --loose-skip-stack-trace --loose-wait-for-pos-timeout=15002022-10-12 8:54:35 0 [Note] /buildbot/amd64-ubuntu-1804-valgrind/build/sql/mariadbd (mysqld 10.5.18-MariaDB-valgrind-max-debug-log) starting as process 99305 ...2022-10-12 8:54:35 0 [Warning] Could not increase number of max_open_files to more than 1012 (request: 32246)2022-10-12 8:54:35 0 [Warning] Changed limits: max_open_files: 1012 max_connections: 151 (was 151) table_cache: 415 (was 2000)2022-10-12 8:54:36 0 [Note] Plugin 'BLACKHOLE' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'partition' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'ARCHIVE' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'FEDERATED' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'S3' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'InnoDB' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'SPHINX' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'CONNECT' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'SEQUENCE' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_BUFFER_PAGE' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_TRX' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_CMP_PER_INDEX' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_METRICS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_CMP' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'THREAD_POOL_WAITS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'THREAD_POOL_QUEUES' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'QUERY_CACHE_INFO' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_LOCKS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_CMPMEM' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'THREAD_POOL_GROUPS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'QUERY_RESPONSE_TIME' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'METADATA_LOCK_INFO' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'user_variables' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'FEEDBACK' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'LOCALES' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'unix_socket' is disabled.2022-10-12 8:54:36 0 [Note] Plugin 'QUERY_RESPONSE_TIME_AUDIT' is disabled.2022-10-12 8:54:36 0 [Warning] /buildbot/amd64-ubuntu-1804-valgrind/build/sql/mariadbd: unknown option '--loose-pam-debug'2022-10-12 8:54:36 0 [Warning] /buildbot/amd64-ubuntu-1804-valgrind/build/sql/mariadbd: unknown option '--loose-aria'2022-10-12 8:54:36 0 [Warning] /buildbot/amd64-ubuntu-1804-valgrind/build/sql/mariadbd: unknown variable 'loose-wait-for-pos-timeout=1500'2022-10-12 8:54:37 0 [Note] Server socket created on IP: '127.0.0.1'.2022-10-12 8:54:37 0 [Note] Reading of all Master_info entries succeeded2022-10-12 8:54:38 0 [Note] Added new Master_info '' to hash table2022-10-12 8:54:38 0 [Note] /buildbot/amd64-ubuntu-1804-valgrind/build/sql/mariadbd: ready for connections.Version: '10.5.18-MariaDB-valgrind-max-debug-log' socket: '/buildbot/amd64-ubuntu-1804-valgrind/build/mysql-test/var/tmp/21/mysqld.1.sock' port: 16380 Source distribution2022-10-12 10:29:43 0 [ERROR] Error in accept: Invalid argument2022-10-12 10:29:43 0 [Note] /buildbot/amd64-ubuntu-1804-valgrind/build/sql/mariadbd (initiated by: unknown): Normal shutdown2022-10-12 10:29:43 0 [Note] Event Scheduler: Purging the queue. 0 events2022-10-12 10:29:43 0 [Note] Debug sync points hit: 11782022-10-12 10:29:43 0 [Note] Debug sync points executed: 02022-10-12 10:29:43 0 [Note] Debug sync points max active per thread: 02022-10-12 10:29:43 0 [Note] /buildbot/amd64-ubuntu-1804-valgrind/build/sql/mariadbd: Shutdown completeUser time 12.09, System time 0.18Maximum resident set size 331264, Integral resident set size 0Non-physical pagefaults 40628, Physical pagefaults 0, Swaps 0Blocks in 0 out 520, Messages in 0 out 0, Signals 0Voluntary context switches 295, Involuntary context switches 250CURRENT_TEST: versioning.online…Test driver log for the same:
10.6 8872d2ee71cc65826909f6a64413ee46d1c5218d
innodb_fts.fulltext 'innodb' w34 [ pass ] 124276innodb_fts.fulltext2 'innodb' w12 [ pass ] 175714***Warnings generated in error logs during shutdown after running tests: perfschema.short_option_12022-10-12 10:29:43 0 [ERROR] Error in accept: Invalid argumentversioning.online 'debug,innodb,timestamp' w21 [ pass ] 24807--------------------------------------------------------------------------The servers were restarted 1725 timesSpent 46687.321 of 6493 seconds executing testcasesCheck of testcase failed for: spider/regression/e1121.direct_join_by_pkey_pkey spider.direct_update_part spider/regression/e1121.load_data_local_ddi1 spider/regression/e112122.load_data_part_replace_ddi0 spider/bugfix.spider_table_stsCompleted: All 4860 tests were successful.Errors/warnings were found in logfiles during server shutdown after running thefollowing sequence(s) of tests:perfschema.short_option_11829 tests were skipped, 1515 by the test itself.mysql-test-run: *** ERROR: There where errors/warnings in server logs after running test cases.program finished with exit code 1elapsedTime=6493.100494If the memcheck process would not have been killed, a 7200-second timeout would have been reported at the end (without any test name), like this:
command timed out: 7200 seconds without output