Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-27782

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

XMLWordPrintable

    • False
    • None
    • False
    • +
    • 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.

      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.

        1. ejb-timer.war
          9 kB

            rhn-support-aogburn Aaron Ogburn
            rhn-support-aogburn Aaron Ogburn
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved: