Bug #62507 Mysql Cluster mysqld Hang
Submitted: 23 Sep 2011 4:02 Modified: 21 Nov 2016 12:30
Reporter: Alan Fok Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Cluster: Cluster (NDB) storage engine Severity:S5 (Performance)
Version:Server version: 5.1.56-ndb-7.1.13-cluste OS:Linux (Centos 5.4 64bit )
Assigned to: Bogdan Kecman CPU Architecture:Any
Tags: Mysql Cluster mysqld Hang ...

[23 Sep 2011 4:02] Alan Fok
Description:
Description:

We have three SQL nodes and two NDBD nodes, one of each on two servers. (And two separate
mgmd node.) SQL Server 1 ,SQL Server 2 and SQL Server 3 have their incoming tcp connections load-balanced (the
load balancer automatically redirects queries in case of a server outage). Currently,
every time I bring up mysqld on server 1, queries start hanging. Server 2 and Server 3 has no such
problems, even with the same queries.
These exact queries have worked fine for weeks, but now they seem to hang this particular
mysql server.

If I do a 'show processlist' on the server, I get a list of the queries it is attempting
to run. Many of which have been running for some time. kill connection <id> or kill query
<id> have no effect. Even "SELECT 1" fails. CPU is usually over 80% _idle_, and memory
usage is around 50% of the 32 GB (per-server).

I've tried restarting the server, but queries start haning again almost immediately.And i need use kill -9 to kill the mysqld service ,then start mysqld ,then it will become to be normal .

The config.ini config 

[ndbd default]
NoOfReplicas=2
DataMemory=22G
IndexMemory=2G
MaxNoOfAttributes = 100000
MaxNoOfTables = 20320
MaxNoOfOrderedIndexes = 100000
MaxNoOfConcurrentOperations = 3000000
TransactionDeadLockDetectionTimeOut = 10000
TimeBetweenLocalCheckpoints = 2
NoOfFragmentLogFiles = 1000
[tcp default]
portnumber=2202

The SQL server my.cnf 

[mysqld]
ndbcluster # run NDB storage engine
ndb-connectstring=192.168.0.73,192.168.0.72
#####Set Slow query Log
slow_query_log = 1
#slow_query_log_file = /usr/local/mysql/mysqld.slow.log
log-slow-queries = /var/log/mysql-slow.log
long_query_time = 5
# Turn off Case sensitive
lower_case_table_names = 1
#Set Max Connection
max_connections = 800
##
table_open_cache = 2048
sort_buffer_size = 8M
read_buffer_size = 8M
read_rnd_buffer_size = 128M
myisam_sort_buffer_size = 32M
thread_cache_size = 512
query_cache_size= 256M
bulk_insert_buffer_size = 512M
back_log=200
tmp_table_size = 64M
long_query_time = 2
binlog_cache_size = 1M
max_allowed_packet = 128M
# Try number of CPU's*2 for thread_concurrency
thread_concurrency = 12
[mysql_cluster]
ndb-connectstring=192.168.0.73,192.168.0.72

Please Help

How to repeat:
At the moment, just have to start the sql servers, and many queries start to hang
immediately. And i need force kill mysqld everyday .

Suggested fix:
Unknown. We are currently limping along on one SQL node of two. Both NDB nodes appear
functional.
[23 Sep 2011 16:36] Matthew Montgomery
Please provide the following for the stuck node:
SHOW FULL PROCESSLIST;
SHOW ENGINE NDB STATUS;
[24 Sep 2011 2:32] Alan Fok
Sorry ! Because It is production server ,so i don't have enough of time to trace the status .i only have "Show process list " :
1       system user                     Daemon  0       Waiting for event from ndbcluster       NULL
2       root    10.1.15.150:45214       e3      Sleep   23              NULL
3       root    10.1.15.150:45215       e3      Sleep   23              NULL
70      root    10.1.15.150:46396       e3      Sleep   23              NULL
15160   root    10.1.15.150:52922       e3      Sleep   5424            NULL
35971   root    10.1.15.150:51360       e3      Sleep   23              NULL
42478   root    10.1.15.10:38779        e3      Query   1355    Sending data    SELECT * FROM (SELECT pt.transactionDatetime,pi.invoiceCreateDatetime ,pi.invoiceId, pi.invoiceNu
mber, pi.invoiceDate, pt.userAmount , pi.invoiceStatus, us2.staffName AS staff ,us.studentName AS userName, us.studentNo AS userNo, CONCAT(sg.gradeName, sc.className) AS classNa
me, pim.itemName FROM e3_payment_invoice pi, e3_user_staff_tw us2, e3_payment_item_tw pim , e3_payment_transaction pt  LEFT JOIN e3_user_student_tw us ON pt.userId=us.userAccId
AND us.studentStatus IN (0,1,2,3)LEFT JOIN e3_school_grade_tw sg ON us.gradeId=sg.gradeId AND sg.gradeStatus=1 LEFT JOIN e3_school_class_tw sc ON us.classId=sc.classId AND sc.cl
assStatus IN (1,2) LEFT JOIN e3_school_class_type_tw sct ON sc.classTypeId=sct.classTypeId AND sct.classTypeStatus=1 WHERE pi.invoiceCreateUserId=us2.userAccId AND pi.schoolId=3
89 AND pi.yearId=603 AND pi.invoiceStatus IN (-2,0,1) AND pi.invoiceStatus<>-2 AND pt.userAccType=1 AND pt.invoiceId=pi.invoiceId AND pt.Id>0 AND us.Id>0 AND pt.transactionStatu
s IN (-2,0,1,2) AND pt.transactionStatus<>-2  AND pi.invoiceDate>='2011-09-01 00:00:00' AND pi.invoiceDate<='2011-09-22 23:59:59' AND pt.categoryItemId = pim.itemId union all SE
LECT pt.transactionDatetime,pi.invoiceCreateDatetime ,pi.invoiceId, pi.invoiceNumber, pi.invoiceDate, pt.userAmount , pi.invoiceStatus, us2.staffName AS staff ,us.studentName AS
 userName, us.studentNo AS userNo, CONCAT(sg.gradeName, sc.className) AS className, productName as itemName FROM e3_payment_invoice pi, e3_user_staff_tw us2, e3_payment_product_
tw pim , e3_payment_transaction pt  LEFT JOIN e3_user_student_tw us ON pt.userId=us.userAccId AND us.studentStatus IN (0,1,2,3)LEFT JOIN e3_school_grade_tw sg ON us.gradeId=sg.g
radeId AND sg.gradeStatus=1 LEFT JOIN e3_school_class_tw sc ON us.classId=sc.classId AND sc.classStatus IN (1,2) LEFT JOIN e3_school_class_type_tw sct ON sc.classTypeId=sct.clas
sTypeId AND sct.classTypeStatus=1 WHERE pi.invoiceCreateUserId=us2.userAccId AND pi.schoolId=389 AND pi.yearId=603 AND pi.invoiceStatus IN (-2,0,1) AND pi.invoiceStatus<>-2 AND
pt.userAccType=1 AND pt.invoiceId=pi.invoiceId AND pt.Id>0 AND us.Id>0 AND pt.transactionStatus IN (-2,0,1,2) AND pt.transactionStatus<>-2  AND pi.invoiceDate>='2011-09-01 00:00
:00' AND pi.invoiceDate<='2011-09-22 23:59:59' AND pt.productId = pim.productId) transInfo GROUP BY invoiceId  ORDER BY  invoiceCreateDatetime DESC LIMIT 0,50
42580   root    10.1.15.10:39238        e3      Query   1315    freeing items   SELECT scheduleType FROM e3_course_schedule WHERE subjectId=22792608 AND gradeId=98969218 AND (cl
assId=68965479 OR classId=-1) AND scheduleStatus=1
42582   root    10.1.15.10:34637        e3      Query   1314    NULL    SELECT DISTINCT us.studentId, us.studentName,us.studentPhoto, us.studentEntryDate, us.studentNo, us.class
Number, us.classId as curClassId, sc.classId, CONCAT(sg.gradeName, sc.className) AS gradeAndClassName, sb.schoolName, us.studentStatus, us.studentSex, ua.userAccPassport, us.stu
dentId,us.userAccId FROM `e3_user_student_trans` ust, `e3_school_base_tw` sb, `e3_school_grade_tw` sg,`e3_school_class_tw` sc,`e3_user_student_tw` us, `e3_user_account` ua WHERE
 ust.schoolId=455 AND ust.schoolId=sb.schoolId AND ust.transToClassId=sc.classId AND sc.gradeId=sg.gradeId AND ust.userAccId=us.userAccId AND ust.userAccId=ua.userAccId AND ust.
transStatus =1 and sg.gradeStatus=1 and sc.classStatus !=-1 AND us.studentStatus=1 AND ust.yearId=799 AND sg.gradeId=2849 AND ust.transToClassId=16441340
42594   root    10.1.15.10:48637        e3      Query   1307    update  INSERT INTO `ebook_usagelog` (`Id`,`SchoolId`,`YearId`,`TermId`,`GradeId`,`ClassId`,`CategoryId`,`Resourc
eId`,`PResourceId`,`UserId`,`MyTeacherId`,`UserType`,`IPAddress`) VALUES (NULL,'69529375','74525860','69570871','98969218','88954140','','10311','325','90563624','11859760','2',
'210.87.254.40')
42597   root    10.1.15.10:30999        e3      Query   1305    end     UPDATE e3_ebook_activation_code SET activationCount=activationCount + 1 WHERE Id=133962
42611   root    10.1.15.10:20141        e3      Query   1299    end     UPDATE e3_ebook_activation_code SET activatedBy='89452856', activatedDatetime=NOW(), activationLastUserAc
cId='89452856', activationStatus=1, activationType='0', activationYearId='42309208', activationTermId='', activationStartDate='2011-09-01', activationEndDate='2012-08-31' WHERE
activationCode='MIIJGPD8' AND activatedBy IS NULL
42615   root    10.1.15.10:46951        e3      Query   1298    update  INSERT INTO `ebook_usagelog` (`Id`,`SchoolId`,`YearId`,`TermId`,`GradeId`,`ClassId`,`CategoryId`,`Resourc
eId`,`PResourceId`,`UserId`,`MyTeacherId`,`UserType`,`IPAddress`) VALUES (NULL,'69529375','74525860','69570871','98969218','88954140','','10311','325','22740806','11859760','2',
'210.87.254.3')
42627   root    10.1.15.10:5157 e3      Query   1291    end     UPDATE e3_user_account SET userAccLastLogin='2011-09-22 13:42:53' WHERE userAccId=30134792
42631   root    10.1.15.10:53790        e3      Query   1291    update  INSERT INTO e3_ebook_activation_limit (userAccId, loginTimes, lastLoginTime) VALUES ('77391206',1,NOW())
42637   root    10.1.15.10:1136 e3      Query   1289    end     UPDATE e3_user_account SET userAccPassword='32b87e5f2280a28e3354c0cd1696c06f' WHERE userAccId=39912428
42644   root    10.1.15.10:36864        e3      Query   1287    update  INSERT INTO e3_ebook_activation_limit (userAccId, loginTimes, lastLoginTime) VALUES ('16134740',1,NOW())
42648   root    10.1.15.10:25711        e3      Query   1286    update  INSERT INTO `resourcevisitlog` (userId,resourceId,resourceWords,startTime,endTime,schoolId,visitType) VAL
UES ('81969804','10811','0','2011-09-22 13:42:58','2011-09-22 13:42:58','411',2)
42657   root    10.1.15.10:31762        e3      Query   1283    end     UPDATE `resourcevisitlog` SET endTime='2011-09-22 13:43:01' WHERE logId='598313'
42664   root    10.1.15.10:39950        e3      Query   1282    end     UPDATE `resourcevisitlog` SET endTime='2011-09-22 13:43:02' WHERE logId='598322'
42668   root    10.1.15.10:26364        e3      Query   1281    update  INSERT INTO `ebook_usagelog` (`Id`,`SchoolId`,`YearId`,`TermId`,`GradeId`,`ClassId`,`CategoryId`,`Resourc
eId`,`PResourceId`,`UserId`,`MyTeacherId`,`UserType`,`IPAddress`) VALUES (NULL,'41741076','72359148','72682137','86208152','80181046','','10083','114','86661291','38467473','2',
'210.87.254.40')
42692   root    10.1.15.10:7360 e3      Query   1271    end     UPDATE `resourcevisitlog` SET endTime='2011-09-22 13:43:12' WHERE logId='598325'
42698   root    10.1.15.10:55990        e3      Query   1268    end     UPDATE e3_ebook_activation_code SET activationCount=activationCount + 1 WHERE Id=132769
--More--

Over 200 Process 

I will try to find out "SHOW ENGINE NDB STATUS; "next time 

Thx
[26 Sep 2011 15:41] Alan Fok
mysql> SHOW ENGINE NDB STATUS;
+------------+-----------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Type       | Name                  | Status                                                                                                                                                             |
+------------+-----------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ndbcluster | connection            | cluster_node_id=5, connected_host=192.168.0.73, connected_port=1186, number_of_data_nodes=2, number_of_ready_data_nodes=2, connect_count=0                         |
| ndbcluster | NdbTransaction        | created=2, free=2, sizeof=360                                                                                                                                      |
| ndbcluster | NdbOperation          | created=4, free=4, sizeof=960                                                                                                                                      |
| ndbcluster | NdbIndexScanOperation | created=0, free=0, sizeof=1168                                                                                                                                     |
| ndbcluster | NdbIndexOperation     | created=0, free=0, sizeof=968                                                                                                                                      |
| ndbcluster | NdbRecAttr            | created=0, free=0, sizeof=88                                                                                                                                       |
| ndbcluster | NdbApiSignal          | created=16, free=16, sizeof=144                                                                                                                                    |
| ndbcluster | NdbLabel              | created=0, free=0, sizeof=200                                                                                                                                      |
| ndbcluster | NdbBranch             | created=0, free=0, sizeof=32                                                                                                                                       |
| ndbcluster | NdbSubroutine         | created=0, free=0, sizeof=72                                                                                                                                       |
| ndbcluster | NdbCall               | created=0, free=0, sizeof=24                                                                                                                                       |
| ndbcluster | NdbBlob               | created=0, free=0, sizeof=496                                                                                                                                      |
| ndbcluster | NdbReceiver           | created=0, free=0, sizeof=144                                                                                                                                      |
| ndbcluster | NdbLockHandle         | created=0, free=0, sizeof=48                                                                                                                                       |
| ndbcluster | binlog                | latest_epoch=15805621383200778, latest_trans_epoch=15805608498298882, latest_received_binlog_epoch=0, latest_handled_binlog_epoch=0, latest_applied_binlog_epoch=0 |
[28 Sep 2011 6:20] Alan Fok
Any update for my bug ...... !!i need restart the mysql API everyday ....!
[21 Nov 2016 12:30] Bogdan Kecman
Hi,

looking at your issue, this is not a bug. MySQL Cluster is not design to run this type of queries and they are inherently slow as performed on a distributed storage engine.

Solutions for your problem 
 - rewrite queries to suit better distributed storage
 - get support to properly rewrite queries

Workaround
 - upgrade to 7.4 as it handle this type of poorly optimized queries better then 7.1

best regards
Bogdan Kecman