AnsweredAssumed Answered

Got lots of Deadlock exception

Question asked by dean on Aug 30, 2017
Latest reply on Sep 2, 2017 by dean

I used Quartz to start timing task, e.g. At 9:00 AM start 1000 instance, bpmn just like this 

 

StartEvent-> ServiceTask -> EndTask, very simple.

 

<?xml version="1.0" encoding="UTF-8"?>
<definitions xmlns="http://www.omg.org/spec/BPMN/20100524/MODEL" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:activiti="http://activiti.org/bpmn" xmlns:bpmndi="http://www.omg.org/spec/BPMN/20100524/DI" xmlns:omgdc="http://www.omg.org/spec/DD/20100524/DC" xmlns:omgdi="http://www.omg.org/spec/DD/20100524/DI" typeLanguage="http://www.w3.org/2001/XMLSchema" expressionLanguage="http://www.w3.org/1999/XPath" targetNamespace="http://www.activiti.org/processdef">
<process id="P467645aa-4a80-8a0a-6a22-e73271b56873" isExecutable="true">
<startEvent id="START"></startEvent>
<sequenceFlow sourceRef="START" targetRef="N-66d5fdc8-6984-4f9a-9156-49fc754aeedc"></sequenceFlow>
<serviceTask id="N-66d5fdc8-6984-4f9a-9156-49fc754aeedc" name="Trigger" activiti:async="true" activiti:delegateExpression="#{triggerWenjuanwangDelegate}">
<extensionElements>
<activiti:field name="parameterMap">
<activiti:string><![CDATA[{"projectId":"590d86baf06eef314f832f3f","shortId":"a2uUb2p","data":{"Q3":"#{contact.mobilePhone}"}}]]></activiti:string>
</activiti:field>
</extensionElements>
</serviceTask>
<endEvent id="N-d39f1d4f-32b7-4870-9f7c-448211edfb54"></endEvent>
<sequenceFlow sourceRef="N-66d5fdc8-6984-4f9a-9156-49fc754aeedc" targetRef="N-d39f1d4f-32b7-4870-9f7c-448211edfb54"></sequenceFlow>
</process>
<bpmndi:BPMNDiagram id="BPMNDiagram_P467645aa-4a80-8a0a-6a22-e73271b56873">
<bpmndi:BPMNPlane bpmnElement="P467645aa-4a80-8a0a-6a22-e73271b56873" id="BPMNPlane_P467645aa-4a80-8a0a-6a22-e73271b56873"></bpmndi:BPMNPlane>
</bpmndi:BPMNDiagram>
</definitions>

Using  activiti:async="true"  in first service task. That's all, but we found lots of Deadlock exception in our test / production env. Mostly occurred in ACT_RU_JOB. We have two app instance as cluster, both contain activiti engine.

I have attached the log file. 

 

MySQL LOG

 

------------------------
LATEST DETECTED DEADLOCK
------------------------
2017-08-31 13:53:32 0x7f2bdb0ea700
*** (1) TRANSACTION:
TRANSACTION 30059034, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 48 lock struct(s), heap size 8400, 162 row lock(s), undo log entries 9
MySQL thread id 1735054, OS thread handle 139826419922688, query id 97268339 10.0.20.2 root update
insert into ACT_RU_JOB (
ID_,
REV_,
TYPE_,
LOCK_OWNER_,
LOCK_EXP_TIME_,
EXCLUSIVE_,
EXECUTION_ID_,
PROCESS_INSTANCE_ID_,
PROC_DEF_ID_,
DUEDATE_,
RETRIES_,
EXCEPTION_STACK_ID_,
EXCEPTION_MSG_,
HANDLER_TYPE_,
HANDLER_CFG_,
TENANT_ID_)
values ('122645',
1,
'message',
null,
null,
1,
'122612',
'122612',
'Pd7abf229-28d2-a864-f780-a8a8de6adf9b:1:120473',
'2017-08-31 13:58:32.127',
3,
null,
null,
'async-continuation',
null,
'1'
)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2534 page no 5 n bits 144 index PRIMARY of table `nazaio`.`act_ru_job` trx id 30059034 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 12 PHYSICAL RECORD: n_fields 19; compact format; info bits 0
0: len 5; hex 3132353136; asc 12516;;
1: len 6; hex 00000079f9ff; asc y ;;
2: len 7; hex 730000021607d0; asc s ;;
3: len 4; hex 80000006; asc ;;
4: len 7; hex 6d657373616765; asc message;;
5: SQL NULL;
6: SQL NULL;
7: len 1; hex 81; asc ;;
8: len 5; hex 3132353037; asc 12507;;
9: len 5; hex 3132353037; asc 12507;;
10: len 30; hex 5035383965656538662d653132622d633661632d356133322d3863656264; asc P589eee8f-e12b-c6ac-5a32-8cebd; (total 45 bytes);
11: len 4; hex 80000000; asc ;;
12: len 5; hex 3132353231; asc 12521;;
13: len 20; hex 466f7220696e70757420737472696e673a202222; asc For input string: "";;
14: len 6; hex 591952e617c0; asc Y R ;;
15: SQL NULL;
16: len 18; hex 6173796e632d636f6e74696e756174696f6e; asc async-continuation;;
17: SQL NULL;
18: len 1; hex 31; asc 1;;

*** (2) TRANSACTION:
TRANSACTION 30059176, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
32 lock struct(s), heap size 3520, 145 row lock(s), undo log entries 9
MySQL thread id 1735056, OS thread handle 139826335491840, query id 97271249 10.0.20.2 root update
insert into ACT_RU_JOB (
ID_,
REV_,
TYPE_,
LOCK_OWNER_,
LOCK_EXP_TIME_,
EXCLUSIVE_,
EXECUTION_ID_,
PROCESS_INSTANCE_ID_,
PROC_DEF_ID_,
DUEDATE_,
RETRIES_,
EXCEPTION_STACK_ID_,
EXCEPTION_MSG_,
HANDLER_TYPE_,
HANDLER_CFG_,
TENANT_ID_)
values ('123313',
1,
'message',
null,
null,
1,
'123301',
'123301',
'Pd7abf229-28d2-a864-f780-a8a8de6adf9b:1:120473',
'2017-08-31 13:58:32.905',
3,
null,
null,
'async-continuation',
null,
'1'
)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 2534 page no 5 n bits 144 index PRIMARY of table `nazaio`.`act_ru_job` trx id 30059176 lock mode S
Record lock, heap no 12 PHYSICAL RECORD: n_fields 19; compact format; info bits 0
0: len 5; hex 3132353136; asc 12516;;
1: len 6; hex 00000079f9ff; asc y ;;
2: len 7; hex 730000021607d0; asc s ;;
3: len 4; hex 80000006; asc ;;
4: len 7; hex 6d657373616765; asc message;;
5: SQL NULL;
6: SQL NULL;
7: len 1; hex 81; asc ;;
8: len 5; hex 3132353037; asc 12507;;
9: len 5; hex 3132353037; asc 12507;;
10: len 30; hex 5035383965656538662d653132622d633661632d356133322d3863656264; asc P589eee8f-e12b-c6ac-5a32-8cebd; (total 45 bytes);
11: len 4; hex 80000000; asc ;;
12: len 5; hex 3132353231; asc 12521;;
13: len 20; hex 466f7220696e70757420737472696e673a202222; asc For input string: "";;
14: len 6; hex 591952e617c0; asc Y R ;;
15: SQL NULL;
16: len 18; hex 6173796e632d636f6e74696e756174696f6e; asc async-continuation;;
17: SQL NULL;
18: len 1; hex 31; asc 1;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2534 page no 5 n bits 144 index PRIMARY of table `nazaio`.`act_ru_job` trx id 30059176 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 12 PHYSICAL RECORD: n_fields 19; compact format; info bits 0
0: len 5; hex 3132353136; asc 12516;;
1: len 6; hex 00000079f9ff; asc y ;;
2: len 7; hex 730000021607d0; asc s ;;
3: len 4; hex 80000006; asc ;;
4: len 7; hex 6d657373616765; asc message;;
5: SQL NULL;
6: SQL NULL;
7: len 1; hex 81; asc ;;
8: len 5; hex 3132353037; asc 12507;;
9: len 5; hex 3132353037; asc 12507;;
10: len 30; hex 5035383965656538662d653132622d633661632d356133322d3863656264; asc P589eee8f-e12b-c6ac-5a32-8cebd; (total 45 bytes);
11: len 4; hex 80000000; asc ;;
12: len 5; hex 3132353231; asc 12521;;
13: len 20; hex 466f7220696e70757420737472696e673a202222; asc For input string: "";;
14: len 6; hex 591952e617c0; asc Y R ;;
15: SQL NULL;
16: len 18; hex 6173796e632d636f6e74696e756174696f6e; asc async-continuation;;
17: SQL NULL;
18: len 1; hex 31; asc 1;;

*** WE ROLL BACK TRANSACTION (2)

Activiti config

@Bean
ProcessEngineConfiguration processEngineConfiguration(DataSource dataSource, @Qualifier("simpleJpaTxManager") PlatformTransactionManager transactionManager) {
    SpringProcessEngineConfiguration processEngineConfiguration = new SpringProcessEngineConfiguration();
    processEngineConfiguration.setDataSource(dataSource);
    processEngineConfiguration.setTransactionManager(transactionManager);
    processEngineConfiguration.setDatabaseSchemaUpdate("true");
    processEngineConfiguration.setJobExecutorActivate(false);
    processEngineConfiguration.setAsyncExecutorEnabled(true);
    processEngineConfiguration.setAsyncExecutorActivate(true);
    processEngineConfiguration.setDelegateExpressionFieldInjectionMode(DelegateExpressionFieldInjectionMode.MIXED);
    processEngineConfiguration.setAsyncExecutorCorePoolSize(asyncExecutorCorePoolSize); // 10
    processEngineConfiguration.setAsyncExecutorMaxPoolSize(asyncExecutorMaxPoolSize); // 25
    processEngineConfiguration.setAsyncExecutorThreadPoolQueueSize(asyncExecutorThreadPoolQueueSize); // 100
    processEngineConfiguration.setAsyncExecutorDefaultTimerJobAcquireWaitTime(1 * 1000);
    return processEngineConfiguration;
}

 

DataBase 

 

private static HikariConfig defaultConfig() {
        HikariConfig config = new HikariConfig();
//        config.setAutoCommit(false);
        config.setAllowPoolSuspension(false);
        config.setConnectionTestQuery("/* ping */ SELECT 1");
        config.setConnectionInitSql("SELECT 1");
        config.setConnectionTimeout(CONNECTION_TIMEOUT);  // 120s
        config.setValidationTimeout(VALIDATION_TIMEOUT);  // 5s
        config.setMaxLifetime(MAX_LIEFTIME); // 300m
        config.setIdleTimeout(IDLE_TIMEOUT); // 120s
        config.setMinimumIdle(MINIMUM_IDLE_SIZE); // 10
        config.setDriverClassName("com.mysql.jdbc.Driver");
        config.setLeakDetectionThreshold(LEAK_DETECTION_THRESHOLD); // 2s
        config.setMaximumPoolSize(MAXIMUM_POOL_SIZE); // 60
        config.setPoolName("MySQLDatabasePool");
        config.setReadOnly(false);
        config.setThreadFactory((r) -> new Thread(r, "MySQLDatabasePool"));
        config.setTransactionIsolation("TRANSACTION_READ_COMMITTED");
        config.addDataSourceProperty("dataSource.cachePrepStmts", true);
        config.addDataSourceProperty("dataSource.prepStmtCacheSize", 250);
        config.addDataSourceProperty("dataSource.prepStmtCacheSqlLimit", 2048);
        config.addDataSourceProperty("dataSource.useServerPrepStmts", true);
        config.addDataSourceProperty("dataSource.useLocalSessionState", true);
        config.addDataSourceProperty("dataSource.useLocalTransactionState", true);
        config.addDataSourceProperty("dataSource.rewriteBatchedStatements", true);
        config.addDataSourceProperty("dataSource.cacheResultSetMetadata", true);
        config.addDataSourceProperty("dataSource.cacheServerConfiguration", true);
        config.addDataSourceProperty("dataSource.elideSetAutoCommits", true);
        config.addDataSourceProperty("dataSource.maintainTimeStats", false);
        return config;
    }

Attachments

Outcomes