Loading...

XML

Word

Printable

Type: Bug
Resolution: Done
Priority: Major
Fix Version/s: 7.4.20.CR1, 7.4.20.GA
Affects Version/s: None
Component/s: Management
Labels:
None

Blocked:
False
Blocked Reason:
None
Ready:
False
CDW devel_ack:
CDW docs_ack:
CDW pm_ack:
CDW qa_ack:
CDW release:
QE Test Coverage:
?
Target Release:

7.4.z.GA
Git Pull Request:
https://github.com/jbossas/wildfly-core-eap/pull/1454
Steps to Reproduce:
Hide

On EAP 7, reproduce EJB timer degradation from this like so:
1. Deploy ejb-timer.war
2. Run simple load and note this can run quite long:

$ ab -c 50 -n 10000 localhost:8080/ejb-timer/HelloWorld Time taken for tests: 169.187 seconds

For comparison, you can test with fewer EJB timers added as children at start up and note this is quite fast:

/standalone.sh -Dexample.seedCount=100 Time taken for tests: 0.432 seconds

The linked simple fix improves my test with 1000000 entries down to ~2 seconds.
Show
On EAP 7, reproduce EJB timer degradation from this like so: 1. Deploy ejb-timer.war 2. Run simple load and note this can run quite long: $ ab -c 50 -n 10000 localhost:8080/ejb-timer/HelloWorld Time taken for tests: 169.187 seconds For comparison, you can test with fewer EJB timers added as children at start up and note this is quite fast: /standalone.sh -Dexample.seedCount=100 Time taken for tests: 0.432 seconds The linked simple fix improves my test with 1000000 entries down to ~2 seconds.
Intelligence Requested:
Market:

SFDC Cases Counter:
SFDC Cases Open:
SFDC Cases Links:

AbstractModelResource$DefaultResourceProvider.hasChildren is inefficient and adds extra processing time while holding a lock. The LinkedHashSet init it forces puts an entry in one at a time. So if its for some resource with many children, the time this takes can scale up quite a lot. And it holds a lock so it can spread contention to other threads.

A notable example of this degradation occurring is the EJB timer sevice on EAP 7 with many child timers:

"default task-14" #513 prio=5 os_prio=0 cpu=4426.76ms elapsed=250.87s tid=0x000056341bf4c800 nid=0x6ce waiting for monitor entry  [0x00007f28a8cd8000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.jboss.as.controller.registry.AbstractModelResource.removeChild(AbstractModelResource.java:195)
	- waiting to lock <0x00000006fa116430> (a java.util.LinkedHashMap)
	at org.jboss.as.ejb3.subsystem.deployment.TimerServiceResource.timerRemoved(TimerServiceResource.java:198)
	at org.jboss.as.ejb3.timerservice.TimerServiceImpl.unregisterTimerResource(TimerServiceImpl.java:1172)
	at org.jboss.as.ejb3.timerservice.TimerServiceImpl.removeTimer(TimerServiceImpl.java:708)

"default task-27" #606 prio=5 os_prio=0 cpu=2451.16ms elapsed=88.70s tid=0x000056341e4e1800 nid=0x7fe runnable  [0x00007f28a7dcb000]
   java.lang.Thread.State: RUNNABLE
	at java.util.HashMap.putVal(java.base@11.0.20/HashMap.java:627)
	at java.util.HashMap.put(java.base@11.0.20/HashMap.java:608)
	at java.util.HashSet.add(java.base@11.0.20/HashSet.java:220)
	at java.util.AbstractCollection.addAll(java.base@11.0.20/AbstractCollection.java:352)
	at java.util.LinkedHashSet.<init>(java.base@11.0.20/LinkedHashSet.java:169)
	at org.jboss.as.controller.registry.AbstractModelResource$DefaultResourceProvider.children(AbstractModelResource.java:272)
	- locked <0x000000072115f158> (a java.util.LinkedHashMap)
	at org.jboss.as.controller.registry.AbstractModelResource$DefaultResourceProvider.hasChildren(AbstractModelResource.java:292)
	at org.jboss.as.controller.registry.AbstractModelResource.removeChild(AbstractModelResource.java:201)
	- locked <0x00000006fa116430> (a java.util.LinkedHashMap)
	at org.jboss.as.ejb3.subsystem.deployment.TimerServiceResource.timerRemoved(TimerServiceResource.java:198)
	at org.jboss.as.ejb3.timerservice.TimerServiceImpl.unregisterTimerResource(TimerServiceImpl.java:1172)
	at org.jboss.as.ejb3.timerservice.TimerServiceImpl.removeTimer(TimerServiceImpl.java:708)

Fortunately it looks like the EJB Timer service itself is improved in latest EAP 8/wildfly by no longer using the AbstractModelResource$DefaultResourceProvider here. But we may want to still add easy optimization to avoid such a scaling concern on the EAP 7 EJB Timer service or anything else that may potentially use AbstractModelResource$DefaultResourceProvider with many children.

- - Sort By Name
  - Sort By Date
  - Ascending
  - Descending
  - Thumbnails
  - List
  - Download All

ejb-timer.war
9 kB
2024/09/09 11:07 PM

causes

JBPM-10240 Operation Delays When Task or Process Contains Multiple Timers Attached

Open

clones

WFCORE-6963 AbstractModelResource$DefaultResourceProvider.hasChildren inefficiency degrades with child count

Resolved

is incorporated by

JBEAP-28050 (7.4.z) Upgrade Wildfly Core from 15.0.39.Final-redhat-00001 to 15.0.40.Final-redhat-00002

QA In Progress

relates to

JBEAP-27782 [GSS](8.0.z) WFCORE-6963 - AbstractModelResource$DefaultResourceProvider.hasChildren inefficiency degrades with child count

Resolved

Assignee:: Aaron Ogburn

Reporter:: Aaron Ogburn

Votes:: 0 Vote for this issue

Watchers:: 8 Start watching this issue

Created:: 2024/08/27 9:37 PM

Updated:: 2024/11/21 1:05 PM

Resolved:: 2024/10/17 9:42 AM

Details

Description

Attachments

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates