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

Segmentation fault (no stack trace), potential dict_operation_lock deadlock, and a foreign key failure

    XMLWordPrintable

Details

    Description

      A user encountered a crash that resulted in no stack trace. The crash came soon after a foreign key error that may or may not be related. After the crash, there were errors printed to the log about long waits for dict_operation_lock.

      The log (see LATEST FOREIGN KEY ERROR section for the foreign key error):

      150921 14:00:07 [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 http://kb.askmonty.org/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.0.17-MariaDB-1~trusty-wsrep-log
      key_buffer_size=16777216
      read_buffer_size=131072
      max_used_connections=5
      max_threads=502
      thread_count=3
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 123347 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x0x7f46d7a3f008
      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 = 0x7f47d50aadc0 thread_stack 0x48000
      InnoDB: Warning: a long semaphore wait:
      --Thread 139942189577984 has waited at srv0srv.cc line 2699 for 241.00 seconds the semaphore:
      X-lock (wait_ex) on RW-latch at 0x7f47d8c41ac0 '&dict_operation_lock'
      a writer (thread id 139942189577984) has reserved it in mode  wait exclusive
      number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
      Last time read locked in file row0purge.cc line 754
      Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.0.17/storage/xtradb/dict/dict0stats.cc line 2391
      InnoDB: Warning: semaphore wait:
      --Thread 139942189577984 has waited at srv0srv.cc line 2699 for 241.00 seconds the semaphore:
      X-lock (wait_ex) on RW-latch at 0x7f47d8c41ac0 '&dict_operation_lock'
      a writer (thread id 139942189577984) has reserved it in mode  wait exclusive
      number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
      Last time read locked in file row0purge.cc line 754
      Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.0.17/storage/xtradb/dict/dict0stats.cc line 2391
      InnoDB: Warning: Writer thread is waiting this semaphore:
      --Thread 139942189577984 has waited at srv0srv.cc line 2699 for 241.00 seconds the semaphore:
      X-lock (wait_ex) on RW-latch at 0x7f47d8c41ac0 '&dict_operation_lock'
      a writer (thread id 139942189577984) has reserved it in mode  wait exclusive
      number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
      Last time read locked in file row0purge.cc line 754
      Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.0.17/storage/xtradb/dict/dict0stats.cc line 2391
      InnoDB: Warning: semaphore wait:
      --Thread 139942156007168 has waited at dict0stats.cc line 2391 for 232.00 seconds the semaphore:
      X-lock on RW-latch at 0x7f47d8c41ac0 '&dict_operation_lock'
      a writer (thread id 139942189577984) has reserved it in mode  wait exclusive
      number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
      Last time read locked in file row0purge.cc line 754
      Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.0.17/storage/xtradb/dict/dict0stats.cc line 2391
      InnoDB: Warning: Writer thread is waiting this semaphore:
      --Thread 139942189577984 has waited at srv0srv.cc line 2699 for 241.00 seconds the semaphore:
      X-lock (wait_ex) on RW-latch at 0x7f47d8c41ac0 '&dict_operation_lock'
      a writer (thread id 139942189577984) has reserved it in mode  wait exclusive
      number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
      Last time read locked in file row0purge.cc line 754
      Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.0.17/storage/xtradb/dict/dict0stats.cc line 2391
      InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
      InnoDB: Pending preads 0, pwrites 0
       
      =====================================
      2015-09-21 14:04:22 7f46d4ffc700 INNODB MONITOR OUTPUT
      =====================================
      Per second averages calculated from the last 57 seconds
      -----------------
      BACKGROUND THREAD
      -----------------
      srv_master_thread loops: 25093 srv_active, 0 srv_shutdown, 5138361 srv_idle
      srv_master_thread log flush and writes: 5163161
      ----------
      SEMAPHORES
      ----------
      OS WAIT ARRAY INFO: reservation count 384933
      --Thread 139942189577984 has waited at srv0srv.cc line 2699 for 246.00 seconds the semaphore:
      X-lock (wait_ex) on RW-latch at 0x7f47d8c41ac0 '&dict_operation_lock'
      a writer (thread id 139942189577984) has reserved it in mode  wait exclusive
      number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
      Last time read locked in file row0purge.cc line 754
      Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.0.17/storage/xtradb/dict/dict0stats.cc line 2391
      --Thread 139942156007168 has waited at dict0stats.cc line 2391 for 237.00 seconds the semaphore:
      X-lock on RW-latch at 0x7f47d8c41ac0 '&dict_operation_lock'
      a writer (thread id 139942189577984) has reserved it in mode  wait exclusive
      number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
      Last time read locked in file row0purge.cc line 754
      Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.0.17/storage/xtradb/dict/dict0stats.cc line 2391
      OS WAIT ARRAY INFO: signal count 369933
      Mutex spin waits 279015, rounds 8166623, OS waits 270913
      RW-shared spins 106652, rounds 3171614, OS waits 105502
      RW-excl spins 5718, rounds 297699, OS waits 8310
      Spin rounds per wait: 29.27 mutex, 29.74 RW-shared, 52.06 RW-excl
      ------------------------
      LATEST FOREIGN KEY ERROR
      ------------------------
      2015-09-21 13:59:02 7f47d710f700 Transaction:
      TRANSACTION 991815, ACTIVE 0 sec updating or deleting
      mysql tables in use 1, locked 1
      126 lock struct(s), heap size 30248, 195 row lock(s), undo log entries 63
      MySQL thread id 1, OS thread handle 0x7f47d710f700, query id 7058904 Delete_rows_log_event::ha_delete_row(440213)
      Foreign key constraint fails for table `db1`.`t`:
      ,
        CONSTRAINT `fk_t` FOREIGN KEY (`p_id`) REFERENCES `p` (`p_id`) ON DELETE SET NULL ON UPDATE NO ACTION
      Trying to add in child table, in index `fk_t_idx` tuple:
      DATA TUPLE: 2 fields;
       0: len 4; hex ; asc   qK;;
       1: len 4; hex ; asc     ;;
       
      But in parent table `db1`.`p`, in index `PRIMARY`,
      the closest match we can find is record:
      PHYSICAL RECORD: n_fields 10; compact format; info bits 32
       0: len 4; hex ; asc   qN;;
       1: len 6; hex ; asc     "G;;
       2: len 7; ; asc N    4f;;
       3: len 9; ; asc d;;
       4: SQL NULL;
       5: SQL NULL;
       6: SQL NULL;
       7: len 30; ; asc Custom Properties for t; (total 38 bytes);
       8: len 1; hex ; asc  ;;
       9: len 4; hex ; asc V   ;;
       
      ------------
      TRANSACTIONS
      ------------
      Trx id counter 991937
      Purge done for trx's n:o < 991935 undo n:o < 0 state: running
      History list length 515
      LIST OF TRANSACTIONS FOR EACH SESSION:
      ---TRANSACTION 991931, not started
      MySQL thread id 1, OS thread handle 0x7f47d710f700, query id 7059512 closing tables
      ---TRANSACTION 29955, not started
      MySQL thread id 3, OS thread handle 0x7f47d7093700, query id 0 Waiting for background binlog tasks
      --------
      FILE I/O
      --------
      I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
      I/O thread 1 state: waiting for completed aio requests (log thread)
      I/O thread 2 state: waiting for completed aio requests (read thread)
      I/O thread 3 state: waiting for completed aio requests (read thread)
      I/O thread 4 state: waiting for completed aio requests (read thread)
      I/O thread 5 state: waiting for completed aio requests (read thread)
      I/O thread 6 state: waiting for completed aio requests (write thread)
      I/O thread 7 state: waiting for completed aio requests (write thread)
      I/O thread 8 state: waiting for completed aio requests (write thread)
      I/O thread 9 state: waiting for completed aio requests (write thread)
      Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
       ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
      Pending flushes (fsync) log: 0; buffer pool: 0
      799 OS file reads, 1677100 OS file writes, 1150379 OS fsyncs
      0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
      -------------------------------------
      INSERT BUFFER AND ADAPTIVE HASH INDEX
      -------------------------------------
      Ibuf: size 1, free list len 0, seg size 2, 1 merges
      merged operations:
       insert 2, delete mark 0, delete 0
      discarded operations:
       insert 0, delete mark 0, delete 0
      0.00 hash searches/s, 0.00 non-hash searches/s
      ---
      LOG
      ---
      Log sequence number 695124068
      Log flushed up to   695124068
      Pages flushed up to 695124068
      Last checkpoint at  695120803
      Max checkpoint age    1469130302
      Checkpoint age target 1423219981
      Modified age          0
      Checkpoint age        3265
      0 pending log writes, 0 pending chkp writes
      967056 log i/o's done, 0.00 log i/o's/second
      ----------------------
      BUFFER POOL AND MEMORY
      ----------------------
      Total memory allocated 2146304000; in additional pool allocated 0
      Total memory allocated by read views 192
      Internal hash tables (constant factor + variable factor)
          Adaptive hash index 37617552 	(36957992 + 659560)
          Page hash           289928 (buffer pool 0 only)
          Dictionary cache    9714573 	(9241616 + 472957)
          File system         841456 	(812272 + 29184)
          Lock system         5189576 	(5188856 + 720)
          Recovery system     0 	(0 + 0)
      Dictionary memory allocated 472957
      InnoDB: ###### Diagnostic info printed to the standard error stream
      InnoDB: Warning: a long semaphore wait:
      --Thread 139942189577984 has waited at srv0srv.cc line 2699 for 272.00 seconds the semaphore:
      X-lock (wait_ex) on RW-latch at 0x7f47d8c41ac0 '&dict_operation_lock'
      a writer (thread id 139942189577984) has reserved it in mode  wait exclusive
      number of readers 1, waiters flag 1, lock_word: ffffffffffffffff
      Last time read locked in file row0purge.cc line 754
      Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.0.17/storage/xtradb/dict/dict0stats.cc line 2391

      Attachments

        Activity

          People

            nirbhay_c Nirbhay Choubey (Inactive)
            GeoffMontee Geoff Montee (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.