Bug 1024013

Summary: BPEL History requests time out with production-level historical data in db
Product: [JBoss] JBoss Fuse Service Works 6 Reporter: Rick Wagner <rwagner>
Component: BPEL IntegrationAssignee: Gary Brown <gbrown>
Status: CLOSED CURRENTRELEASE QA Contact: lvaskova
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.0.0 GACC: gbrown, ldimaggi, mweiler, rwagner, soa-p-jira
Target Milestone: ER7   
Target Release: 6.0.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: 1022587 Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Rick Wagner 2013-10-28 15:05:56 UTC
+++ This bug was initially created as a clone of Bug #1022587 +++

The BPEL History console times out and gives an error message when production-level amounts of data are in the database.

Reproducer:  

- Set up SOA-P, point it to a database other than the default.  (i.e. MySQL)
- Deploy bpel_hello_world quickstart
- Deploy bpel_esb_helloworld quickstart - Run 'ant deploy' ->  Using the BPEL console, check the history.  (Should show ok)
- Now, change bpel_esb_helloworld/src/../SendEsbMessage to send 1000 messages:
    	for(int i=0; i<1000; i++) {
        	esbMessage.getBody().add(args[2] + " NUMBER #" + i);        	
            Message respMessage = new ServiceInvoker(args[0], args[1]).deliverSync(esbMessage, 5000);        	
            System.out.println("REPLY: "+respMessage.getBody().get());
        }
- Check history again (should fail)

----------------------------------------------------------------------------
Alternative reproducer:  Use SOAPUI to make a 'testcase' with > 1k repeats.


The problem seems to be in queries to the EVENT_DATA_TABLE:

Enabled SQL logging shows the following events:
1. DefaultBPAFDataSource.getInstanceEvents() method calls the following SQL:
29193:2013-10-23 15:10:39,322 DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-1) select event0_.EID as EID132_, event0_.ACTIVITY_DEFINITION_ID as ACTIVITY2_132_, event0_.ACTIVITY_INSTANCE_ID as ACTIVITY3_132_, event0_.ACTIVITY_NAME as ACTIVITY4_132_, event0_.CU
RRENT_STATE as CURRENT5_132_, event0_.PREVIOUS_STATE as PREVIOUS6_132_, event0_.PROCESS_DEFINITION_ID as PROCESS7_132_, event0_.PROCESS_INSTANCE_ID as PROCESS8_132_, event0_.PROCESS_NAME as PROCESS9_132_, event0_.SERVER_ID as SERVER10_132_, event0_.TIMESTAMP a
s TIMESTAMP132_ from BPAF_EVENT event0_, BPAF_EVENT event1_ where event0_.PROCESS_DEFINITION_ID=event1_.PROCESS_DEFINITION_ID and event0_.PROCESS_INSTANCE_ID=event1_.PROCESS_INSTANCE_ID and (event0_.CURRENT_STATE=? and event1_.CURRENT_STATE=? or event1_.CURREN
T_STATE=? and event0_.CURRENT_STATE=?) and (event0_.ACTIVITY_DEFINITION_ID is null) and (event1_.ACTIVITY_DEFINITION_ID is null) and event0_.PROCESS_DEFINITION_ID='{http://www.jboss.org/bpel/examples}HelloWorld-1' and event0_.TIMESTAMP>=? and event1_.TIMESTAMP
<=? order by event0_.EID
29194:2013-10-23 15:10:39,324 DEBUG [org.hibernate.type.EnumType] (http-127.0.0.1-8080-1) Binding 'Open_Running' to parameter: 1
29195:2013-10-23 15:10:39,324 DEBUG [org.hibernate.type.EnumType] (http-127.0.0.1-8080-1) Binding 'Closed_Completed' to parameter: 2
29196:2013-10-23 15:10:39,324 DEBUG [org.hibernate.type.EnumType] (http-127.0.0.1-8080-1) Binding 'Open_Running' to parameter: 3
29197:2013-10-23 15:10:39,324 DEBUG [org.hibernate.type.EnumType] (http-127.0.0.1-8080-1) Binding 'Closed_Completed' to parameter: 4
29198:2013-10-23 15:10:39,324 TRACE [org.hibernate.type.LongType] (http-127.0.0.1-8080-1) binding '1044054000000' to parameter: 5
29199:2013-10-23 15:10:39,324 TRACE [org.hibernate.type.LongType] (http-127.0.0.1-8080-1) binding '1382527990209' to parameter: 6

and returns in ~1 second => OK

2. ProcessHistoryPluginImpl then seems to call the following SQL in a loop (~20.000 times for ~1000 instances):
DEBUG [org.hibernate.SQL] (http-127.0.0.1-8080-1) select dataelemen0_.EVENT_ID as EVENT4_132_1_, dataelemen0_.TID as TID1_, dataelemen0_.TID as TID133_0_, dataelemen0_.EVENT_ID as EVENT4_133_0_, dataelemen0_.NAME as NAME133_0_, da
taelemen0_.VALUE as VALUE133_0_ from BPAF_EVENT_DATA dataelemen0_ where dataelemen0_.EVENT_ID=?

Step 2 above takes a long time, resulting in a timeout at the BPEL Console.

Comment 2 JBoss JIRA Server 2013-11-01 14:38:13 UTC
Gary Brown <gary> updated the status of jira RIFTSAW-544 to Resolved

Comment 3 lvaskova 2013-12-21 18:54:45 UTC
Verified on ER7