[MDEV-15648] MariaDB becomes often unresponsive Created: 2018-03-23  Updated: 2018-05-28  Resolved: 2018-05-28

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2.13
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Mathieu Migout Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: need_feedback
Environment:

10.2.13-MariaDB-10.2.13+maria~xenial-log


Attachments: File my.cnf    
Issue Links:
Relates
relates to MDEV-15707 Long semaphore wait : deadlock in In... Closed

 Description   

Since we migrated from MariaDb 5.5 to MariaDB 10.2.13, MariaDBServer become often unreponsive:

  • all thread are stuck in opening table status
  • lot of InnoDB: A long semaphore wait Waring in lig

We have to kill and restart mariaDb server.

Example:

On 2018-03-23, MariaDb hang at 8:28. At this times, there is an attempt to restaure a dump generate with MySQL 5.5.18 for Win64.
.

Log

2018-03-23  8:32:43 140401445676800 [Warning] InnoDB: A long semaphore wait:
--Thread 140401323267840 has waited at row0row.cc line 988 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x7fbb5ed79b18 created in file buf0buf.cc line 1471
a writer (thread id 140401340053248) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: ffffffffdfffffff
Last time read locked in file row0row.cc line 988
Last time write locked in file btr0cur.cc line 1917
2018-03-23  8:32:43 140401445676800 [Warning] InnoDB: A long semaphore wait:
--Thread 140401340053248 has waited at btr0cur.cc line 1917 for 241.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x7fbd21a936a0 created in file buf0buf.cc line 1471
a writer (thread id 140401340053248) has reserved it in mode  wait exclusive
number of readers 1, waiters flag 0, lock_word: ffffffffffffffff
Last time read locked in file row0row.cc line 988
Last time write locked in file buf0flu.cc line 1236
2018-03-23  8:32:43 140401445676800 [Warning] InnoDB: A long semaphore wait:
--Thread 140400859473664 has waited at row0ins.cc line 1926 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x55b134618c50 created in file dict0dict.cc line 1107
a writer (thread id 140401408464640) has reserved it in mode  wait exclusive
number of readers 3, waiters flag 1, lock_word: fffffffffffffffd
Last time read locked in file row0ins.cc line 1926
Last time write locked in file row0mysql.cc line 3383
2018-03-23  8:32:43 140401445676800 [Warning] InnoDB: A long semaphore wait:
--Thread 140401314875136 has waited at row0purge.cc line 853 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x55b134618c50 created in file dict0dict.cc line 1107
a writer (thread id 140401408464640) has reserved it in mode  wait exclusive
number of readers 3, waiters flag 1, lock_word: fffffffffffffffd
Last time read locked in file row0ins.cc line 1926
Last time write locked in file row0mysql.cc line 3383
2018-03-23  8:32:43 140401445676800 [Warning] InnoDB: A long semaphore wait:
--Thread 140401331660544 has waited at fsp0fsp.cc line 2821 for 241.00 seconds the semaphore:
X-lock on RW-latch at 0x55b1345efe40 created in file fil0fil.cc line 1551
a writer (thread id 140401340053248) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file not yet reserved line 0
Last time write locked in file fsp0fsp.cc line 2821
2018-03-23  8:32:43 140401445676800 [Warning] InnoDB: A long semaphore wait:
--Thread 140401408464640 has waited at row0mysql.cc line 3383 for 241.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x55b134618c50 created in file dict0dict.cc line 1107
a writer (thread id 140401408464640) has reserved it in mode  wait exclusive
number of readers 3, waiters flag 1, lock_word: fffffffffffffffd
Last time read locked in file row0ins.cc line 1926
Last time write locked in file row0mysql.cc line 3383
2018-03-23  8:32:43 140401445676800 [Warning] InnoDB: A long semaphore wait:
--Thread 140400655324928 has waited at row0ins.cc line 1926 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x55b134618c50 created in file dict0dict.cc line 1107
a writer (thread id 140401408464640) has reserved it in mode  wait exclusive
number of readers 3, waiters flag 1, lock_word: fffffffffffffffd
Last time read locked in file row0ins.cc line 1926
Last time write locked in file row0mysql.cc line 3383
2018-03-23  8:32:43 140401445676800 [Warning] InnoDB: A long semaphore wait:
--Thread 140400030902016 has waited at row0mysql.cc line 1783 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x55b134618c50 created in file dict0dict.cc line 1107
a writer (thread id 140401408464640) has reserved it in mode  wait exclusive
number of readers 3, waiters flag 1, lock_word: fffffffffffffffd
Last time read locked in file row0ins.cc line 1926
Last time write locked in file row0mysql.cc line 3383
2018-03-23  8:32:43 140401445676800 [Warning] InnoDB: A long semaphore wait:
--Thread 140400016656128 has waited at row0ins.cc line 1926 for 241.00 seconds the semaphore:
S-lock on RW-latch at 0x55b134618c50 created in file dict0dict.cc line 1107
a writer (thread id 140401408464640) has reserved it in mode  wait exclusive
number of readers 3, waiters flag 1, lock_word: fffffffffffffffd
Last time read locked in file row0ins.cc line 1926
Last time write locked in file row0mysql.cc line 3383
2018-03-23  8:32:43 140401445676800 [Note] InnoDB: A semaphore wait:
--Thread 140400038479616 has waited at row0upd.cc line 183 for 150.00 seconds the semaphore:
S-lock on RW-latch at 0x55b134618c50 created in file dict0dict.cc line 1107
a writer (thread id 140401408464640) has reserved it in mode  wait exclusive
number of readers 3, waiters flag 1, lock_word: fffffffffffffffd
Last time read locked in file row0ins.cc line 1926
Last time write locked in file row0mysql.cc line 3383
2018-03-23  8:32:43 140401445676800 [Note] InnoDB: A semaphore wait:

.h3 Dump

-- MySQL dump 10.13  Distrib 5.5.18, for Win64 (x86)
--
-- Host: 127.0.0.1    Database: db_horizon_transport_rodr04_01
-- ------------------------------------------------------
-- Server version	5.5.18
 
/*!40101 SET @OLD_CHARACTER_SET_CLIENT=@@CHARACTER_SET_CLIENT */;
/*!40101 SET @OLD_CHARACTER_SET_RESULTS=@@CHARACTER_SET_RESULTS */;
/*!40101 SET @OLD_COLLATION_CONNECTION=@@COLLATION_CONNECTION */;
/*!40101 SET NAMES latin1 */;
/*!40103 SET @OLD_TIME_ZONE=@@TIME_ZONE */;
/*!40103 SET TIME_ZONE='+00:00' */;
/*!40014 SET @OLD_UNIQUE_CHECKS=@@UNIQUE_CHECKS, UNIQUE_CHECKS=0 */;
/*!40014 SET @OLD_FOREIGN_KEY_CHECKS=@@FOREIGN_KEY_CHECKS, FOREIGN_KEY_CHECKS=0 */;
/*!40101 SET @OLD_SQL_MODE=@@SQL_MODE, SQL_MODE='NO_AUTO_VALUE_ON_ZERO' */;
/*!40111 SET @OLD_SQL_NOTES=@@SQL_NOTES, SQL_NOTES=0 */;
 
--
-- Current Database: `db_horizon_transport_rodr04_01`
--
 
/*!40000 DROP DATABASE IF EXISTS `db_horizon_transport_rodr04_01`*/;
 
CREATE DATABASE /*!32312 IF NOT EXISTS*/ `db_horizon_transport_rodr04_01` /*!40100 DEFAULT CHARACTER SET latin1 */;
 
USE `db_horizon_transport_rodr04_01`;
 
--
-- Table structure for table `db_version_ver`
--
 
DROP TABLE IF EXISTS `db_version_ver`;
/*!40101 SET @saved_cs_client     = @@character_set_client */;
/*!40101 SET character_set_client = utf8 */;
CREATE TABLE `db_version_ver` (
  `ver_id` int(11) NOT NULL AUTO_INCREMENT,
  `ver_num` int(11) DEFAULT NULL,
  `ver_libelle` varchar(45) DEFAULT NULL,
  `ver_date` datetime DEFAULT NULL,
  PRIMARY KEY (`ver_id`)
) ENGINE=InnoDB AUTO_INCREMENT=877 DEFAULT CHARSET=latin1;
/*!40101 SET character_set_client = @saved_cs_client */;



 Comments   
Comment by Elena Stepanova [ 2018-04-01 ]

How do you know that it's this table all threads are working with?
What exactly they are doing, which SQL statements are they performing?
Can you acquire all threads' stack trace from the process while it's in this state?

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