Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-6656

Test wsrep.variables hangs

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 10.0.12-galera
    • Fix Version/s: 10.0.13-galera
    • Component/s: None
    • Labels:
      None
    • Environment:
      Linux Mint 17,uname -a
      Linux jan-GE70-0NC-0ND 3.13.0-29-generic #53-Ubuntu SMP Wed Jun 4 21:00:20 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux,
      gcc --version
      gcc (Ubuntu 4.8.2-19ubuntu1) 4.8.2

      Description

      Test case hangs maybe not every time but very often.

      Using debug build, I run test case with following:

      jan@jan-GE70-0NC-0ND ~/mysql/10.0-galera/mysql-test $ ./mysql-test-run --vardir=/dev/shm wsrep.variables --ddd --mysqld=--wsrep-debug=1
      Logging: ./mysql-test-run  --vardir=/dev/shm wsrep.variables --ddd --mysqld=--wsrep-debug=1
      vardir: /run/shm
      Checking leftover processes...
      Removing old var directory...
      couldn't chmod(0777, /run/shm/sem.ADBE_REL_mdm): Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      Couldn't delete file '/run/shm/sem.ADBE_REL_mdm': Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      couldn't chmod(0777, /run/shm/sem.ADBE_WritePrefs_mdm): Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      Couldn't delete file '/run/shm/sem.ADBE_WritePrefs_mdm': Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      couldn't chmod(0777, /run/shm/sem.ADBE_ReadPrefs_mdm): Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      Couldn't delete file '/run/shm/sem.ADBE_ReadPrefs_mdm': Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      couldn't chmod(0777, /run/shm): Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 853.
      Couldn't remove directory '/run/shm': Permission denied at /usr/share/perl/5.18/File/Find.pm line 853.
      Creating var directory '/run/shm'...
      Checking supported features...
      MariaDB Version 10.0.12-MariaDB-wsrep-debug
       - SSL connections supported
       - binaries are debug compiled
       - binaries built with wsrep patch
       - adding wsrep, galera to default test suites
      Collecting tests...
      Installing system database...
       
      ==============================================================================
       
      TEST                                      RESULT   TIME (ms) or COMMENT
      --------------------------------------------------------------------------
       
      worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
      ^Cmysql-test-run: *** ERROR: Got ^C signal
      jan@jan-GE70-0NC-0ND ~/mysql/10.0-galera/mysql-test $ killall -9 mysqld
      jan@jan-GE70-0NC-0ND ~/mysql/10.0-galera/mysql-test $ ./mysql-test-run --vardir=/dev/shm wsrep.variables --ddd --mysqld=--wsrep-debug=1
      Logging: ./mysql-test-run  --vardir=/dev/shm wsrep.variables --ddd --mysqld=--wsrep-debug=1
      vardir: /run/shm
      Checking leftover processes...
      Removing old var directory...
      couldn't chmod(0777, /run/shm/sem.ADBE_REL_mdm): Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      Couldn't delete file '/run/shm/sem.ADBE_REL_mdm': Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      couldn't chmod(0777, /run/shm/sem.ADBE_WritePrefs_mdm): Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      Couldn't delete file '/run/shm/sem.ADBE_WritePrefs_mdm': Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      couldn't chmod(0777, /run/shm/sem.ADBE_ReadPrefs_mdm): Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      Couldn't delete file '/run/shm/sem.ADBE_ReadPrefs_mdm': Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 796.
      couldn't chmod(0777, /run/shm): Operation not permitted at /usr/share/perl/5.18/File/Find.pm line 853.
      Couldn't remove directory '/run/shm': Permission denied at /usr/share/perl/5.18/File/Find.pm line 853.
      Creating var directory '/run/shm'...
      Checking supported features...
      MariaDB Version 10.0.12-MariaDB-wsrep-debug
       - SSL connections supported
       - binaries are debug compiled
       - binaries built with wsrep patch
       - adding wsrep, galera to default test suites
      Collecting tests...
      Installing system database...
       
      ==============================================================================
       
      TEST                                      RESULT   TIME (ms) or COMMENT
      --------------------------------------------------------------------------
       
      worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019

      And ddd output

      GNU DDD 3.3.12 (x86_64-pc-linux-gnu), by Dorothea Lütkehaus and Andreas Zeller.
      Copyright © 1995-1999 Technische Universität Braunschweig, Germany.
      Copyright © 1999-2001 Universität Passau, Germany.
      Copyright © 2001 Universität des Saarlandes, Germany.
      Copyright © 2001-2004 Free Software Foundation, Inc.
      Reading symbols from /home/jan/mysql/10.0-galera/sql/mysqld...done.
      (gdb) run
      Starting program: /home/jan/mysql/10.0-galera/sql/mysqld --defaults-group-suffix=.1 --defaults-file=/run/shm/my.cnf --log-output=file --gdb --wsrep-debug=1 --core-file --loose-debug-sync-timeout=300 
      [Thread debugging using libthread_db enabled]
      Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
      [New Thread 0x7ffff5bff700 (LWP 20091)]
      [Thread 0x7ffff5bff700 (LWP 20091) exited]
      [New Thread 0x7ffff5bff700 (LWP 20092)]
      140828 15:18:55 [Note] Plugin 'InnoDB' is disabled.
      140828 15:18:55 [Note] Plugin 'XTRADB_READ_VIEW' is disabled.
      140828 15:18:55 [Note] Plugin 'XTRADB_INTERNAL_HASH_TABLES' is disabled.
      140828 15:18:55 [Note] Plugin 'XTRADB_RSEG' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_TRX' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_CMPMEM' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_BUFFER_PAGE' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_METRICS' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
      140828 15:18:55 [Note] Plugin 'INNODB_CHANGED_PAGES' is disabled.
      140828 15:18:55 [Note] Plugin 'partition' is disabled.
      140828 15:18:55 [Warning] /home/jan/mysql/10.0-galera/sql/mysqld: unknown variable 'loose-feedback-user-info=mysql-test'
      140828 15:18:55 [Note] WSREP: Initial TC log open: dummy
      140828 15:18:55 [Note] Server socket created on IP: '0.0.0.0'.
      [New Thread 0x7ffff7fc4700 (LWP 20093)]
      140828 15:18:55 [Note] Event Scheduler: Loaded 0 events
      140828 15:18:55 [Note] WSREP: Setting wsrep_ready to 0
      140828 15:18:55 [Note] WSREP: Read nil XID from storage engines, skipping position init
      140828 15:18:55 [Note] WSREP: wsrep_load(): loading provider library 'none'
      140828 15:18:55 [Note] WSREP: Setting wsrep_ready to 1
      140828 15:18:55 [Note] [Debug] WSREP: dummy_init
      [New Thread 0x7ffff7f7b700 (LWP 20097)]
      140828 15:18:55 [Note] /home/jan/mysql/10.0-galera/sql/mysqld: ready for connections.
      Version: '10.0.12-MariaDB-wsrep-debug-log'  socket: '/run/shm/tmp/mysqld.1.sock'  port: 16000  Source distribution, wsrep_25.10.r4002
      [Thread 0x7ffff7f7b700 (LWP 20097) exited]
      [New Thread 0x7ffff7f7b700 (LWP 20098)]
      140828 15:18:55 [Note] [Debug] WSREP: dummy_stats_get
      140828 15:18:55 [Note] [Debug] WSREP: dummy_stats_free
      [Thread 0x7ffff7f7b700 (LWP 20098) exited]
      [New Thread 0x7ffff7f7b700 (LWP 20102)]
      140828 15:18:55 [Note] WSREP: wsrep_provider_update: /usr/lib/galera/libgalera_smm.so
      140828 15:18:55 [Note] WSREP: Stop replication
      140828 15:18:55 [Note] WSREP: Provider disconnect
      140828 15:18:55 [Note] [Debug] WSREP: dummy_disconnect
      140828 15:18:57 [Note] WSREP: waiting for client connections to close: 1
      140828 15:18:57 [Note] [Debug] WSREP: dummy_free
      140828 15:18:57 [Note] WSREP: Setting wsrep_ready to 0
      140828 15:18:57 [Note] WSREP: Read nil XID from storage engines, skipping position init
      140828 15:18:57 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
      140828 15:18:57 [Note] WSREP: wsrep_load(): Galera 3.5(rXXXX) by Codership Oy <info@codership.com> loaded successfully.
      140828 15:18:57 [Note] WSREP: CRC-32C: using hardware acceleration.
      140828 15:18:57 [Warning] WSREP: Could not open saved state file for reading: /run/shm/mysqld.1/data//grastate.dat
      140828 15:18:57 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1
      140828 15:18:57 [Note] WSREP: Passing config to GCS: base_host = 178.251.60.217; base_port = 4567; cert.log_conflicts = no; debug = no; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 1; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /run/shm/mysqld.1/data/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /run/shm/mysqld.1/data//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false; pc.ignore_sb = false; pc.npvo = false; pc.version = 0; pc.wait_prim = true; pc.wait_prim_timeout = P30S; pc.w
      [New Thread 0x7fffe53f0700 (LWP 20109)]
      140828 15:18:58 [Note] WSREP: Service thread queue flushed.
      140828 15:18:58 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
      140828 15:18:58 [Note] WSREP: wsrep_cluster_address_init:  -> null
      140828 15:18:58 [Note] WSREP: refresh_provider_options: null
      140828 15:18:58 [Note] WSREP: wsrep_provider_update: none
      140828 15:18:58 [Note] WSREP: Stop replication
      140828 15:18:58 [Note] WSREP: Provider disconnect
      140828 15:19:00 [Note] WSREP: waiting for client connections to close: 1
      140828 15:19:00 [Note] WSREP: dtor state: CLOSED
      140828 15:19:00 [Note] WSREP: apply mon: entered 0
      140828 15:19:00 [Note] WSREP: apply mon: entered 0
      140828 15:19:00 [Note] WSREP: apply mon: entered 0
      140828 15:19:00 [Note] WSREP: cert index usage at exit 0
      140828 15:19:00 [Note] WSREP: cert trx map usage at exit 0
      140828 15:19:00 [Note] WSREP: deps set usage at exit 0
      140828 15:19:00 [Note] WSREP: avg deps dist 0
      140828 15:19:00 [Note] WSREP: avg cert interval 0
      140828 15:19:00 [Note] WSREP: cert index size 0
      140828 15:19:00 [Note] WSREP: Service thread queue flushed.
      140828 15:19:00 [Note] WSREP: wsdb trx map usage 0 conn query map usage 0
      [Thread 0x7fffe53f0700 (LWP 20109) exited]
      140828 15:19:00 [Note] WSREP: Flushing memory map to disk...
      140828 15:19:00 [Note] WSREP: Setting wsrep_ready to 0
      140828 15:19:00 [Note] WSREP: Read nil XID from storage engines, skipping position init
      140828 15:19:00 [Note] WSREP: wsrep_load(): loading provider library 'none'
      140828 15:19:00 [Note] WSREP: Setting wsrep_ready to 1
      140828 15:19:00 [Note] [Debug] WSREP: dummy_init
      140828 15:19:00 [Note] WSREP: wsrep_cluster_address_init: null -> null
      140828 15:19:00 [Note] WSREP: refresh_provider_options: null
      140828 15:19:00 [Note] [Debug] WSREP: dummy_options_get
      140828 15:19:00 [Note] WSREP: wsrep_provider_update: /usr/lib/galera/libgalera_smm.so
      140828 15:19:00 [Note] WSREP: Stop replication
      140828 15:19:00 [Note] WSREP: Provider disconnect
      140828 15:19:00 [Note] [Debug] WSREP: dummy_disconnect
      140828 15:19:02 [Note] WSREP: waiting for client connections to close: 1
      140828 15:19:02 [Note] [Debug] WSREP: dummy_free
      140828 15:19:02 [Note] WSREP: Setting wsrep_ready to 0
      140828 15:19:02 [Note] WSREP: Read nil XID from storage engines, skipping position init
      140828 15:19:02 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
      140828 15:19:02 [Note] WSREP: wsrep_load(): Galera 3.5(rXXXX) by Codership Oy <info@codership.com> loaded successfully.
      140828 15:19:02 [Note] WSREP: CRC-32C: using hardware acceleration.
      140828 15:19:02 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1
      140828 15:19:02 [Note] WSREP: Passing config to GCS: base_host = 178.251.60.217; base_port = 4567; cert.log_conflicts = no; debug = no; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 1; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /run/shm/mysqld.1/data/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /run/shm/mysqld.1/data//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; ist.recv_addr = 178.251.60.217; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false; pc.ignore_sb = false; pc.npvo = false; pc.version = 0; pc.wait_prim = true; p
      [New Thread 0x7fffe53f0700 (LWP 20117)]
      140828 15:19:02 [Note] WSREP: Service thread queue flushed.
      140828 15:19:02 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
      140828 15:19:02 [Note] WSREP: wsrep_cluster_address_init: null -> null
      140828 15:19:02 [Note] WSREP: refresh_provider_options: null
      140828 15:19:02 [Note] WSREP: wsrep_provider_update: none
      140828 15:19:02 [Note] WSREP: Stop replication
      140828 15:19:02 [Note] WSREP: Provider disconnect
      140828 15:19:04 [Note] WSREP: waiting for client connections to close: 1
      140828 15:19:04 [Note] WSREP: dtor state: CLOSED
      140828 15:19:04 [Note] WSREP: apply mon: entered 0
      140828 15:19:04 [Note] WSREP: apply mon: entered 0
      140828 15:19:04 [Note] WSREP: apply mon: entered 0
      140828 15:19:04 [Note] WSREP: cert index usage at exit 0
      140828 15:19:04 [Note] WSREP: cert trx map usage at exit 0
      140828 15:19:04 [Note] WSREP: deps set usage at exit 0
      140828 15:19:04 [Note] WSREP: avg deps dist 0
      140828 15:19:04 [Note] WSREP: avg cert interval 0
      140828 15:19:04 [Note] WSREP: cert index size 0
      140828 15:19:04 [Note] WSREP: Service thread queue flushed.
      140828 15:19:04 [Note] WSREP: wsdb trx map usage 0 conn query map usage 0
      [Thread 0x7fffe53f0700 (LWP 20117) exited]
      140828 15:19:04 [Note] WSREP: Flushing memory map to disk...
      140828 15:19:04 [Note] WSREP: Setting wsrep_ready to 0
      140828 15:19:04 [Note] WSREP: Read nil XID from storage engines, skipping position init
      140828 15:19:04 [Note] WSREP: wsrep_load(): loading provider library 'none'
      140828 15:19:04 [Note] WSREP: Setting wsrep_ready to 1
      140828 15:19:04 [Note] [Debug] WSREP: dummy_init
      140828 15:19:04 [Note] WSREP: wsrep_cluster_address_init: null -> null
      140828 15:19:04 [Note] WSREP: refresh_provider_options: null
      140828 15:19:04 [Note] [Debug] WSREP: dummy_options_get
      140828 15:19:04 [Note] [Debug] WSREP: dummy_stats_get
      140828 15:19:04 [Note] [Debug] WSREP: dummy_stats_free
      140828 15:19:04 [Note] [Debug] WSREP: dummy_stats_get
      140828 15:19:04 [Note] [Debug] WSREP: dummy_stats_free
      140828 15:19:04 [Note] WSREP: wsrep_provider_update: /usr/lib/galera/libgalera_smm.so
      140828 15:19:04 [Note] WSREP: Stop replication
      140828 15:19:04 [Note] WSREP: Provider disconnect
      140828 15:19:04 [Note] [Debug] WSREP: dummy_disconnect
      140828 15:19:06 [Note] WSREP: waiting for client connections to close: 1
      140828 15:19:06 [Note] [Debug] WSREP: dummy_free
      140828 15:19:06 [Note] WSREP: Setting wsrep_ready to 0
      140828 15:19:06 [Note] WSREP: Read nil XID from storage engines, skipping position init
      140828 15:19:06 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
      140828 15:19:06 [Note] WSREP: wsrep_load(): Galera 3.5(rXXXX) by Codership Oy <info@codership.com> loaded successfully.
      140828 15:19:06 [Note] WSREP: CRC-32C: using hardware acceleration.
      140828 15:19:06 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1
      140828 15:19:06 [Note] WSREP: Passing config to GCS: base_host = 178.251.60.217; base_port = 4567; cert.log_conflicts = no; debug = no; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 1; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /run/shm/mysqld.1/data/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /run/shm/mysqld.1/data//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; ist.recv_addr = 178.251.60.217; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false; pc.ignore_sb = false; pc.npvo = false; pc.version = 0; pc.wait_prim = true; p
      [New Thread 0x7fffe53f0700 (LWP 20124)]
      140828 15:19:06 [Note] WSREP: Service thread queue flushed.
      140828 15:19:06 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
      140828 15:19:06 [Note] WSREP: wsrep_cluster_address_init: null -> null
      140828 15:19:06 [Note] WSREP: refresh_provider_options: null
      140828 15:19:06 [Note] WSREP: Stop replication
      140828 15:19:06 [Note] WSREP: Provider disconnect
      140828 15:19:08 [Note] WSREP: waiting for client connections to close: 1
      safe_mutex: Found wrong usage of mutex 'LOCK_wsrep_slave_threads' and 'LOCK_global_system_variables'
      Mutex currently locked (in reverse order):
      LOCK_global_system_variables      /home/jan/mysql/10.0-galera/sql/wsrep_var.cc  line 343
      LOCK_wsrep_slave_threads          /home/jan/mysql/10.0-galera/sql/sys_vars_shared.h  line 55
      140828 15:19:08 [Note] WSREP: Start replication
      140828 15:19:08 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
      140828 15:19:08 [Note] WSREP: protonet asio version 0
      140828 15:19:08 [Note] WSREP: Using CRC-32C (optimized) for message checksums.
      140828 15:19:08 [Note] WSREP: backend: asio
      140828 15:19:08 [Note] WSREP: GMCast version 0
      140828 15:19:08 [Note] WSREP: (8286b8c5-2ead-11e4-a515-fa3203f0f2b7, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
      140828 15:19:08 [Note] WSREP: (8286b8c5-2ead-11e4-a515-fa3203f0f2b7, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
      140828 15:19:08 [Note] WSREP: EVS version 0
      140828 15:19:08 [Note] WSREP: PC version 0
      140828 15:19:08 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer ''
      140828 15:19:08 [Note] WSREP: Node 8286b8c5-2ead-11e4-a515-fa3203f0f2b7 state prim
      140828 15:19:08 [Note] WSREP: view(view_id(PRIM,8286b8c5-2ead-11e4-a515-fa3203f0f2b7,1) memb {
      	8286b8c5-2ead-11e4-a515-fa3203f0f2b7,0
      } joined {
      } left {
      } partitioned {
      })
      [New Thread 0x7fffe27ff700 (LWP 20125)]
      140828 15:19:08 [Note] WSREP: gcomm: connected
      140828 15:19:08 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
      [New Thread 0x7fffe17ff700 (LWP 20126)]
      140828 15:19:08 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
      140828 15:19:08 [Note] WSREP: Opened channel 'my_wsrep_cluster'
      140828 15:19:08 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
      [New Thread 0x7ffff7f32700 (LWP 20127)]
      [New Thread 0x7ffff7ee9700 (LWP 20128)]
      140828 15:19:08 [Note] WSREP: Starting new group from scratch: 829129a0-2ead-11e4-be1f-0b20a4cabe2f
      140828 15:19:08 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 82913900-2ead-11e4-9ce8-5358a4a82b69
      140828 15:19:08 [Note] WSREP: STATE EXCHANGE: sent state msg: 82913900-2ead-11e4-9ce8-5358a4a82b69
      140828 15:19:08 [Note] WSREP: STATE EXCHANGE: got state msg: 82913900-2ead-11e4-9ce8-5358a4a82b69 from 0 (jan-GE70-0NC-0ND)
      140828 15:19:08 [Note] WSREP: Quorum results:
      	version    = 3,
      	component  = PRIMARY,
      	conf_id    = 0,
      	members    = 1/1 (joined/total),
      	act_id     = 0,
      	last_appl. = -1,
      	protocols  = 0/5/3 (gcs/repl/appl),
      	group UUID = 829129a0-2ead-11e4-be1f-0b20a4cabe2f
      140828 15:19:08 [Note] WSREP: Flow-control interval: [16, 16]
      140828 15:19:08 [Note] WSREP: Restored state OPEN -> JOINED (0)
      140828 15:19:08 [Note] WSREP: Member 0.0 (jan-GE70-0NC-0ND) synced with group.
      140828 15:19:08 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 0)
      140828 15:19:08 [Note] WSREP: New cluster view: global state: 829129a0-2ead-11e4-be1f-0b20a4cabe2f:0, view# 1: Primary, number of nodes: 1, my index: 0, protocol version 3
      140828 15:19:08 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      140828 15:19:08 [Note] WSREP: REPL Protocols: 5 (3, 1)
      140828 15:19:08 [Note] WSREP: Service thread queue flushed.
      140828 15:19:08 [Note] WSREP: Assign initial position for certification: 0, protocol version: 3
      140828 15:19:08 [Note] WSREP: Service thread queue flushed.
      140828 15:19:08 [Note] WSREP: Synchronized with group, ready for connections
      140828 15:19:08 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      140828 15:19:08 [Note] WSREP: Nobody is waiting for SST.
      [New Thread 0x7ffff7ea0700 (LWP 20129)]
      [New Thread 0x7ffff7e57700 (LWP 20130)]
      [New Thread 0x7ffff6575700 (LWP 20131)]
      [New Thread 0x7ffff652c700 (LWP 20132)]
      [New Thread 0x7ffff64e3700 (LWP 20133)]
      [New Thread 0x7ffff649a700 (LWP 20134)]
      [New Thread 0x7ffff6451700 (LWP 20135)]
      [New Thread 0x7ffff51a0700 (LWP 20136)]
      [New Thread 0x7ffff5157700 (LWP 20137)]
      140828 15:19:14 [Note] WSREP: wsrep_provider_update: none
      140828 15:19:14 [Note] WSREP: Stop replication
      140828 15:19:14 [Note] WSREP: Provider disconnect
      140828 15:19:14 [Note] WSREP: Closing send monitor...
      140828 15:19:14 [Note] WSREP: Closed send monitor.
      140828 15:19:14 [Note] WSREP: gcomm: terminating thread
      140828 15:19:14 [Note] WSREP: gcomm: joining thread
      140828 15:19:14 [Note] WSREP: gcomm: closing backend
      [Thread 0x7fffe27ff700 (LWP 20125) exited]
      140828 15:19:14 [Note] WSREP: view((empty))
      140828 15:19:14 [Note] WSREP: Received self-leave message.
      140828 15:19:14 [Note] WSREP: gcomm: closed
      140828 15:19:14 [Note] WSREP: Flow-control interval: [0, 0]
      140828 15:19:14 [Note] WSREP: Received SELF-LEAVE. Closing connection.
      140828 15:19:14 [Note] WSREP: Shifting SYNCED -> CLOSED (TO: 0)
      140828 15:19:14 [Note] WSREP: RECV thread exiting 0: Success
      140828 15:19:14 [Note] WSREP: New cluster view: global state: 829129a0-2ead-11e4-be1f-0b20a4cabe2f:0, view# -1: non-Primary, number of nodes: 0, my index: -1, protocol version 3
      140828 15:19:14 [Note] WSREP: Setting wsrep_ready to 0
      140828 15:19:14 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:0)
      140828 15:19:14 [Note] WSREP: closing applier 12
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 10
      [Thread 0x7fffe17ff700 (LWP 20126) exited]
      140828 15:19:14 [Note] WSREP: recv_thread() joined.
      140828 15:19:14 [Note] WSREP: Closing replication queue.
      140828 15:19:14 [Note] WSREP: Closing slave action queue.
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:6)
      140828 15:19:14 [Note] WSREP: closing applier 9
      [Thread 0x7ffff6451700 (LWP 20135) exited]
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 9
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:6)
      140828 15:19:14 [Note] WSREP: closing applier 14
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:6)
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:6)
      [Thread 0x7ffff64e3700 (LWP 20133) exited]
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:6)
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:6)
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:6)
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:6)
      140828 15:19:14 [Note] WSREP: applier thread exiting (code:6)
      140828 15:19:14 [Note] WSREP: closing applier 6
      140828 15:19:14 [Note] WSREP: closing applier 7
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 8
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 7
      140828 15:19:14 [Note] WSREP: closing applier 8
      140828 15:19:14 [Note] WSREP: closing applier 5
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 6
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 5
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 4
      140828 15:19:14 [Note] WSREP: closing applier 13
      140828 15:19:14 [Note] WSREP: closing applier 10
      [Thread 0x7ffff652c700 (LWP 20132) exited]
      140828 15:19:14 [Note] WSREP: closing applier 11
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 3
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 2
      140828 15:19:14 [Note] WSREP: wsrep running threads now: 1
      [Thread 0x7ffff51a0700 (LWP 20136) exited]
      [Thread 0x7ffff5157700 (LWP 20137) exited]
      [Thread 0x7ffff7ea0700 (LWP 20129) exited]
      [Thread 0x7ffff7e57700 (LWP 20130) exited]
      [Thread 0x7ffff649a700 (LWP 20134) exited]
      [Thread 0x7ffff6575700 (LWP 20131) exited]
      [Thread 0x7ffff7ee9700 (LWP 20128) exited]
      140828 15:19:16 [Note] WSREP: waiting for client connections to close: 2
      140828 15:19:16 [Note] WSREP: closing wsrep thread 4
      140828 15:19:16 [Note] WSREP: WSREP rollback thread wakes for signal
      140828 15:19:16 [Note] WSREP: WSREP rollback thread has empty abort queue
      140828 15:19:16 [Note] WSREP: rollbacker thread exiting
      140828 15:19:16 [Note] WSREP: wsrep running threads now: 0
      [Thread 0x7ffff7f32700 (LWP 20127) exited]
      ^C
      Program received signal SIGINT, Interrupt.
      0x00007ffff6a8203d in poll () at ../sysdeps/unix/syscall-template.S:81
       
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) 
      file: "../sysdeps/unix/syscall-template.S", line number: 1
      (gdb) (gdb) thread apply all bt
       
      Thread 10 (Thread 0x7fffe53f0700 (LWP 20124)):
      #0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
      #1  0x00007fffed96899e in wait (this=0x7fffe53efce0, cond=...) at galerautils/src/gu_lock.hpp:56
      #2  galera::ServiceThd::thd_func (arg=0x7fffee0ba590) at galera/src/galera_service_thd.cpp:30
      #3  0x00007ffff7570182 in start_thread (arg=0x7fffe53f0700) at pthread_create.c:312
      #4  0x00007ffff6a8f38d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
       
      Thread 7 (Thread 0x7ffff7f7b700 (LWP 20102)):
      #0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
      #1  0x0000000000ea3229 in safe_cond_wait (cond=0x1a13dc0 <COND_thread_count>, mp=0x1a12d00 <LOCK_thread_count>, file=0x106aa20 "/home/jan/mysql/10.0-galera/include/mysql/psi/mysql_thread.h", line=1154) at /home/jan/mysql/10.0-galera/mysys/thr_mutex.c:493
      #2  0x00000000005b491e in inline_mysql_cond_wait (that=0x1a13dc0 <COND_thread_count>, mutex=0x1a12d00 <LOCK_thread_count>, src_file=0x106c700 "/home/jan/mysql/10.0-galera/sql/mysqld.cc", src_line=5717) at /home/jan/mysql/10.0-galera/include/mysql/psi/mysql_thread.h:1154
      #3  0x00000000005bf25a in wsrep_wait_appliers_close (thd=0x7ffff0741070) at /home/jan/mysql/10.0-galera/sql/mysqld.cc:5717
      #4  0x000000000081305d in wsrep_stop_replication (thd=0x7ffff0741070) at /home/jan/mysql/10.0-galera/sql/wsrep_mysqld.cc:774
      #5  0x000000000081ddb8 in wsrep_provider_update (self=0x1a31ce0 <_ZL18Sys_wsrep_provider>, thd=0x7ffff0741070, type=OPT_GLOBAL) at /home/jan/mysql/10.0-galera/sql/wsrep_var.cc:238
      #6  0x00000000005d7bc6 in sys_var::update (this=0x1a31ce0 <_ZL18Sys_wsrep_provider>, thd=0x7ffff0741070, var=0x7fffee1a1250) at /home/jan/mysql/10.0-galera/sql/set_var.cc:196
      #7  0x00000000005da056 in set_var::update (this=0x7fffee1a1250, thd=0x7ffff0741070) at /home/jan/mysql/10.0-galera/sql/set_var.cc:776
      #8  0x00000000005d9c1e in sql_set_variables (thd=0x7ffff0741070, var_list=0x7ffff0745cc0) at /home/jan/mysql/10.0-galera/sql/set_var.cc:679
      #9  0x00000000006829fc in mysql_execute_command (thd=0x7ffff0741070) at /home/jan/mysql/10.0-galera/sql/sql_parse.cc:4084
      #10 0x000000000068b47b in mysql_parse (thd=0x7ffff0741070, rawbuf=0x7fffee1a1088 "SET GLOBAL wsrep_provider= none", length=31, parser_state=0x7ffff7f7a1d0) at /home/jan/mysql/10.0-galera/sql/sql_parse.cc:6977
      #11 0x000000000068abec in wsrep_mysql_parse (thd=0x7ffff0741070, rawbuf=0x7fffee1a1088 "SET GLOBAL wsrep_provider= none", length=31, parser_state=0x7ffff7f7a1d0) at /home/jan/mysql/10.0-galera/sql/sql_parse.cc:6799
      #12 0x000000000067bf84 in dispatch_command (command=COM_QUERY, thd=0x7ffff0741070, packet=0x7fffefb8f071 "SET GLOBAL wsrep_provider= none", packet_length=31) at /home/jan/mysql/10.0-galera/sql/sql_parse.cc:1483
      #13 0x000000000067ac9b in do_command (thd=0x7ffff0741070) at /home/jan/mysql/10.0-galera/sql/sql_parse.cc:1088
      #14 0x00000000007a50f5 in do_handle_one_connection (thd_arg=0x7ffff0741070) at /home/jan/mysql/10.0-galera/sql/sql_connect.cc:1396
      #15 0x00000000007a4e4d in handle_one_connection (arg=0x7ffff0741070) at /home/jan/mysql/10.0-galera/sql/sql_connect.cc:1307
      #16 0x0000000000b42ad9 in pfs_spawn_thread (arg=0x7ffff5c226f0) at /home/jan/mysql/10.0-galera/storage/perfschema/pfs.cc:1860
      #17 0x00007ffff7570182 in start_thread (arg=0x7ffff7f7b700) at pthread_create.c:312
      #18 0x00007ffff6a8f38d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
       
      Thread 4 (Thread 0x7ffff7fc4700 (LWP 20093)):
      #0  0x00007ffff75780d1 in do_sigwait (sig=0x7ffff7fc3d90, set=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/../../../../../sysdeps/unix/sysv/linux/sigwait.c:60
      #1  __sigwait (set=0x7ffff7fc3dc0, sig=0x7ffff7fc3d90) at ../nptl/sysdeps/unix/sysv/linux/../../../../../sysdeps/unix/sysv/linux/sigwait.c:97
      #2  0x00000000005ba49e in signal_hand (arg=0x0) at /home/jan/mysql/10.0-galera/sql/mysqld.cc:3481
      #3  0x0000000000b42ad9 in pfs_spawn_thread (arg=0x7ffff5c208f0) at /home/jan/mysql/10.0-galera/storage/perfschema/pfs.cc:1860
      #4  0x00007ffff7570182 in start_thread (arg=0x7ffff7fc4700) at pthread_create.c:312
      #5  0x00007ffff6a8f38d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
       
      Thread 3 (Thread 0x7ffff5bff700 (LWP 20092)):
      #0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
      #1  0x0000000000ea352b in safe_cond_timedwait (cond=0x2240260 <COND_checkpoint>, mp=0x22401a0 <LOCK_checkpoint>, abstime=0x7ffff5bfed90, file=0x11825b0 "/home/jan/mysql/10.0-galera/include/mysql/psi/mysql_thread.h", line=1191) at /home/jan/mysql/10.0-galera/mysys/thr_mutex.c:547
      #2  0x0000000000a8d3a9 in inline_mysql_cond_timedwait (that=0x2240260 <COND_checkpoint>, mutex=0x22401a0 <LOCK_checkpoint>, abstime=0x7ffff5bfed90, src_file=0x11825f0 "/home/jan/mysql/10.0-galera/storage/maria/ma_servicethread.c", src_line=119) at /home/jan/mysql/10.0-galera/include/mysql/psi/mysql_thread.h:1191
      #3  0x0000000000a8d88f in my_service_thread_sleep (control=0x1847070 <checkpoint_control>, sleep_time=30000000000) at /home/jan/mysql/10.0-galera/storage/maria/ma_servicethread.c:118
      #4  0x0000000000a8257a in ma_checkpoint_background (arg=0x1e) at /home/jan/mysql/10.0-galera/storage/maria/ma_checkpoint.c:709
      #5  0x0000000000b42ad9 in pfs_spawn_thread (arg=0x7ffff5c20170) at /home/jan/mysql/10.0-galera/storage/perfschema/pfs.cc:1860
      #6  0x00007ffff7570182 in start_thread (arg=0x7ffff5bff700) at pthread_create.c:312
      #7  0x00007ffff6a8f38d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
       
      Thread 1 (Thread 0x7ffff7fc67c0 (LWP 20087)):
      #0  0x00007ffff6a8203d in poll () at ../sysdeps/unix/syscall-template.S:81
      #1  0x00000000005c1127 in handle_connections_sockets () at /home/jan/mysql/10.0-galera/sql/mysqld.cc:6859
      #2  0x00000000005c00ca in mysqld_main (argc=119, argv=0x7ffff5c7e4c0) at /home/jan/mysql/10.0-galera/sql/mysqld.cc:6285
      #3  0x00000000005b428d in main (argc=8, argv=0x7fffffffc7e8) at /home/jan/mysql/10.0-galera/sql/main.cc:25
      (gdb) 

      Problem is that galera slave thread end signaling does not always work and there is no more slave threads but we still wait on condition variable.

        Attachments

          Activity

            People

            Assignee:
            jplindst Jan Lindström
            Reporter:
            jplindst Jan Lindström
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: