Details
-
Bug
-
Resolution: Done
-
Critical
-
7.4.1.GA
-
- CaseManagement
- kie-server
-
2019 Week 47-49 (from Nov 18), 2019 Week 50-52 (from Dec 9), 2020 Week 01-03 (from Dec 30)
Description
Lots of queries against ContextMappingInfo when satisfying Milestone.
Steps to reproduce:
1) Deploy querycase-1.0.jar to kie-server. You can confirm the process test.bpmn inside the jar.
2) Start 10 cases
curl -u rhpamAdmin:password1! -X POST "http://localhost:8080/kie-server/services/rest/server/containers/querycase/cases/test/instances?bridgeEndpoint=true" -H "accept: application/json" -H "content-type: application/json" -d "{\"case-data\" : {}, \"case-user-assignments\" : {\"owner\" : \"rhpamAdmin\"}}"
3) Update one case to satisfy its Milestone
curl -u rhpamAdmin:password1! -X POST "http://localhost:8080/kie-server/services/rest/server/containers/querycase/cases/instances/CASE-0000000016/caseFile?bridgeEndpoint=true" -H "accept: application/json" -H "content-type: application/json" -d "{\"stateId\" : 2042}"
It calls JpaProcessPersistenceContext.getProcessInstancesWaitingForEvent() so all process instance IDs are returned.
2019-11-15 16:53:56,759 DEBUG [org.hibernate.SQL] (default task-4) select processins0_.InstanceId as col_0_0_ from ProcessInstanceInfo processins0_ inner join EventTypes eventtypes1_ on processins0_.InstanceId=eventtypes1_.InstanceId where eventtypes1_.element=? 2019-11-15 16:53:56,759 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] (default task-4) binding parameter [1] as [VARCHAR] - [RuleFlow-Milestone-test-2] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [1] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [2] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [3] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [4] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [5] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [6] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [7] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [8] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [9] 2019-11-15 16:53:56,760 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] (default task-4) extracted value ([col_0_0_] : [BIGINT]) - [10]
Then, ContextMappingInfo is queried for all process instance IDs.
2019-11-15 16:53:56,760 DEBUG [org.hibernate.SQL] (default task-4) select contextmap0_.mappingId as mappingI1_8_, contextmap0_.CONTEXT_ID as CONTEXT_2_8_, contextmap0_.KSESSION_ID as KSESSION3_8_, contextmap0_.OWNER_ID as OWNER_ID4_8_, contextmap0_.OPTLOCK as OPTLOCK5_8_ from ContextMappingInfo contextmap0_ where contextmap0_.CONTEXT_ID=? and contextmap0_.OWNER_ID=? 2019-11-15 16:53:56,761 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] (default task-4) binding parameter [1] as [VARCHAR] - [1] ... 2019-11-15 16:53:56,762 DEBUG [org.hibernate.SQL] (default task-4) select contextmap0_.mappingId as mappingI1_8_, contextmap0_.CONTEXT_ID as CONTEXT_2_8_, contextmap0_.KSESSION_ID as KSESSION3_8_, contextmap0_.OWNER_ID as OWNER_ID4_8_, contextmap0_.OPTLOCK as OPTLOCK5_8_ from ContextMappingInfo contextmap0_ where contextmap0_.CONTEXT_ID=? and contextmap0_.OWNER_ID=? 2019-11-15 16:53:56,762 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] (default task-4) binding parameter [1] as [VARCHAR] - [2] ...
In customer's case, it hits more than 16000 cases hence it takes 10 sec.