1 2 Previous Next 21 Replies Latest reply: Feb 22, 2010 10:43 AM by Kabir Khan RSS

Profiling the dependency project

Kabir Khan Master

Since the indexing dependency resolver I have been working on does not yield the performance improvements I was hoping for, I am now benchmarking the dependency project in isolation. It makes profiling a lot easier since there is a lot less other things going on which is the case when starting up the application server. My thinking now is that we should do the same for the other MC modules.

 

One thing is to not try to resolve contexts that are in the INSTALLED state (or where the toState is invalid) from AbstractController.resolveContexts(boolean), this shaves off about 20% for contexts installed in the right order. See http://community.jboss.org/message/524747#524747 for a description of the benchmark.

 

         for (ControllerState fromState : stateModel)
         {
            ControllerState toState = stateModel.getNextState(fromState);
-            if (resolveContexts(fromState, toState, trace))
+           
+            if (stateModel.isValidState(toState))
            {
-               resolutions = true;
-               break;
+               if (resolveContexts(fromState, toState, trace))
+               {
+                  resolutions = true;
+                  break;
+               }
            }
         }
      }

 

Another simple thing that cuts deploying 2000 contexts

-with dependencies in the right order from 852ms->789ms

-with dependencies in the right order from 12788ms->8320ms

is to further modify resolveContexts to not break out of the loop once it resolves some contexts for a state, e.g.

 

      boolean resolutions = true;
      while (resolutions || onDemandEnabled)
      {
         if (onDemandEnabled)
            wasOnDemandEnabled = true;
         onDemandEnabled = false;
         resolutions = false;
         for (ControllerState fromState : stateModel)
         {
            ControllerState toState = stateModel.getNextState(fromState);

            if (stateModel.isValidState(toState))
            {
               if (resolveContexts(fromState, toState, trace))
               {
                  resolutions = true;
//                  break;  // Don't exit here
               }
            }
         }
      }
Profiling this for 500 contexts reduces the number of calls to the nested resolveContexts from
-17,500 to 7000 (right order)
-17,500 to 10,493 (wrong order), a bit down the line we end up with 377K instead of 627K calls to resolveDependencies()
All tests pass apart from the ones mentioned in http://community.jboss.org/message/524862#524862 which I know how to fix if Ales agrees:

kabir.khan@jboss.com wrote:

 

I mean this:

 

   public void testPlainLifecycleDependencyWrongOrder() throws Throwable

   {

      plainLifecycleDependencyWrongOrder();

 

      ControllerContext context2 = assertInstall(1, "Name2", ControllerState.CONFIGURED);

      ControllerContext context1 = assertInstall(0, "Name1");

      assertEquals(ControllerState.INSTALLED, context2.getState());

 

      SimpleBeanWithLifecycle bean1 = (SimpleBeanWithLifecycle) context1.getTarget();

      assertNotNull(bean1);

 

      SimpleBeanWithLifecycle bean2 = (SimpleBeanWithLifecycle) context2.getTarget();

      assertNotNull(bean2);

 

      assertEquals(1, bean1.createOrder);

      assertEquals(2, bean2.createOrder);

      assertEquals(3, bean1.startOrder);

      assertEquals(4, bean2.startOrder);

   }

The new resolver works with

      assertEquals(1, bean1.createOrder);

      assertEquals(2, bean1.startOrder);

      assertEquals(3, bean2.createOrder);

      assertEquals(4, bean2.startOrder);

The actual hardcoded orders of beans 1 and 2 is an implemetation detail as I see it. The real check is making sure that the initial install of context 2 does not go beyond CONFIGURED and:
bean1.startOrder > bean1.createOrder
bean2.startOrder > bean2.createOrder
bean2.createOrder > bean1.createOrder
bean2.startOrder > bean1.startOrder
I've got an infinite loop in the indexing resolver when I start up AS which I need to fix before I can get any measurements of boot time, although it sounds like we won't gain much from this.
  • 1. Re: Profiling the dependency project
    Ales Justin Master

    is to further modify resolveContexts to not break out of the loop once it resolves some contexts for a state, e.g.

     

          boolean resolutions = true;
          while (resolutions || onDemandEnabled)
          {
             if (onDemandEnabled)
                wasOnDemandEnabled = true;
     
             onDemandEnabled = false;
             resolutions = false;
             for (ControllerState fromState : stateModel)
             {
                ControllerState toState = stateModel.getNextState(fromState);
     
                if (stateModel.isValidState(toState))
                {
                   if (resolveContexts(fromState, toState, trace))
                   {
                      resolutions = true;
    //                  break;  // Don't exit here
                   }
                }
             }
          }
    


    Can you do a proof check (proof by-design) that this doesn't break the resolve logic.

    At first sight it looks harmless, but we must make sure it's really OK.

    e.g. 2nd resolve would resolve same contexts in both scenarios

     

    All tests pass apart from the ones mentioned in http://community.jboss.org/message/524862#524862 which I know how to fix if Ales agrees:

    kabir.khan@jboss.com wrote:

     

    I mean this:

     

       public void testPlainLifecycleDependencyWrongOrder() throws Throwable

       {

          plainLifecycleDependencyWrongOrder();

     

          ControllerContext context2 = assertInstall(1, "Name2", ControllerState.CONFIGURED);

          ControllerContext context1 = assertInstall(0, "Name1");

          assertEquals(ControllerState.INSTALLED, context2.getState());

     

          SimpleBeanWithLifecycle bean1 = (SimpleBeanWithLifecycle) context1.getTarget();

          assertNotNull(bean1);

     

          SimpleBeanWithLifecycle bean2 = (SimpleBeanWithLifecycle) context2.getTarget();

          assertNotNull(bean2);

     

          assertEquals(1, bean1.createOrder);

          assertEquals(2, bean2.createOrder);

          assertEquals(3, bean1.startOrder);

          assertEquals(4, bean2.startOrder);

       }

    The new resolver works with

          assertEquals(1, bean1.createOrder);

          assertEquals(2, bean1.startOrder);

          assertEquals(3, bean2.createOrder);

          assertEquals(4, bean2.startOrder);

    The actual hardcoded orders of beans 1 and 2 is an implemetation detail as I see it. The real check is making sure that the initial install of context 2 does not go beyond CONFIGURED and:
    bean1.startOrder > bean1.createOrder
    bean2.startOrder > bean2.createOrder
    bean2.createOrder > bean1.createOrder
    bean2.startOrder > bean1.startOrder

    This does look like an impl detail, so you're fine to change it.

  • 2. Re: Profiling the dependency project
    Kabir Khan Master

    Can you do a proof check (proof by-design) that this doesn't break the resolve logic.

    At first sight it looks harmless, but we must make sure it's really OK.

    e.g. 2nd resolve would resolve same contexts in both scenarios

    As discussed offline with Ales, I am not doing this fix for alpha6:

                if (stateModel.isValidState(toState))
                {
                   if (resolveContexts(fromState, toState, trace))
                   {
                      resolutions = true;
    //                  break;  // Don't exit here
                   }
                }

  • 3. Re: Profiling the dependency project
    Kabir Khan Master
    We do quite a lot of adding to and removing from AbstractController.installed and the sets stored in AbstractController.contextsByState. They are currently implemented as CopyOnWriteArraySets which perform badly when there are large numbers of entries in the sets already. I tried replacing these with ConcurrentSet (based on ConcurrentHashMap), but that performed worse. I've spoken to Jason who gave me a few ideas, but will put those off until I've picked off a few other things.
  • 4. Re: Profiling the dependency project
    Kabir Khan Master

    AbstractController.resolveCallbacks() was spending a lot of time setting/unsetting the thread context classloader, so I have changed that to avoid doing that unless there actually are some callbacks to install

     

    http://fisheye.jboss.org/changelog/JBossAS?cs=100775

     

    These calls are probably heavier than they would normally be in the AS since the tests are running with a security manager enabled meaning we need to create the PrivilegedAction and go via AccessController.doPrivileged although calling Thread.get/setContextClassloader() seems to have some overhead of its own especially when it was being done once each time a context enters a state.

  • 5. Re: Profiling the dependency project
    Kabir Khan Master

    kabir.khan@jboss.com wrote:

     

    We do quite a lot of adding to and removing from AbstractController.installed and the sets stored in AbstractController.contextsByState. They are currently implemented as CopyOnWriteArraySets which perform badly when there are large numbers of entries in the sets already. I tried replacing these with ConcurrentSet (based on ConcurrentHashMap), but that performed worse. I've spoken to Jason who gave me a few ideas, but will put those off until I've picked off a few other things.

    What I forgot to mention here is that the perfomance of these sets is related to the size. COWAS performs better than ConcurrentSet when a small number of exisiting entries are present, which probably makes it ok for the 'installing' set since that will not contain that many entries. It does however degrade its performance rapidly when there are many entries there, so it is probably not the best choice for the sets stored in 'contextsByState'.

     

    This little test demonstrates the difference:

    public class SetBenchmark
    {
       static int prefill = 1000;
       
       static int iterations = 10000000;
       
       public static void main(String[] args)
       {
          Set<String> set = new CopyOnWriteArraySet<String>();
    //      Set<String> set = new ConcurrentSet();
    //      Set<String> set = new HashSet<String>();
    //      Set<String> set = new ConcurrentSkipListSet<String>();
          
          for (int i = 0 ; i < prefill ; i++)
          {
             set.add("XYZ" + i);
          }
          
          long start = System.currentTimeMillis();
          for (int i = 0 ; i < iterations ; i++)
          {
             set.add("XXX" + i);
             set.remove("XXX" + i);
          }
          System.out.println("-----> " + (System.currentTimeMillis() - start));
       }
    }
     
    

     

    The times in ms for various amounts of prefill, COWAS, normal HashSet, ConcurrentSkipListSet and ConcurrentSet:

    prefill 0

    ------------

    COWAS: 4648 4397 4618 4430 4460

    CS: 5141 5026 5177 4908 5139

    HS: 4267 3954 3762 4070 3952

    CSLS: 5475 5504 5461 5649 5406

     

    prefill 10

    ----------

    COWAS: 6781 7026 6502 6505

    CS: 5009 4954 4791 5168

    HS: 4165 4403 4206

    CSLS: 6046 6291 6216

     

    prefill 100

    -----------

    COWAS: 29138 31600

    CS: 5115 5208 5179 5511

    HS: 4378 4525 4098 4181

    CSLS: 6836 7029 6721

     

    prefill 1000

    ------------

    COWAS: About 5 minutes

    CS: 5030 5212

    CSLS: 8488 7627 7797

    HS: 4141 4085

     

    So this might explain why CS makes performance worse when used for contextsByState's sets, in my benchmark most states will have very few entries and only a few willl have lots of entries. CSLS always seems to be slower than CS so we won't go with that.

     

    A few of Jason's suggestions were;

    - Create own COWAS implementation based on FastCopyHashMap

    - Try a normal synchronized HashSet (need to make sure first that the way we use it we don't iterate over the entries)

    - ConcurrentSkipListMap although its performance degrades with performance (evaluated above)

  • 6. Re: Profiling the dependency project
    Kabir Khan Master

    Regarding the contextsByState sets

    - Try a normal synchronized HashSet (need to make sure first that the way we use it we don't iterate over the entries)

    From what I can see, all usage within the main sources seem to be with the read/writeLock taken so we could possibly just use a plain HashSet, apart from this in AbstractContextRegistry:

     

       public Set<ControllerContext> getContextsByState(ControllerState state)

       {

          return controller.getContextsByState(state);

       }

    I can't see any usage of this, so I am unsure what the consequences of exposing this would be?

     

    Average time in ms for 10,000 contexts in the correct order:

    -1850 with COWAS

    -1074 with plain HashSet

     

    Average time in ms for 500 contexts in the wrong order:

    -1180 with COWAS

    -1140 with plain HashSet

     

    However since getContextsByState() is in the spi and its implemetation is straightforward we probably want some flavour of concurrent set, so I'll look at the FastCopyHashMap implementation

       public Set<ControllerContext> getContextsByState(ControllerState state)

       {

          return contextsByState.get(state);

       }

  • 7. Re: Profiling the dependency project
    Kabir Khan Master

    I created a FastCopyOnWriteSet implementation, unfortunately its performance degrades a lot with performance as well:

     

    prefill 0: 7634ms

    prefill 10: 9127ms

    prefill 100: 27898ms

     

    I have attached the source, but I guess it is the copying upon modification that is the main overhead of the FCOWS and COWAS? Putting this into the contextsByState I see a slight worsening in performance.

  • 8. Re: Profiling the dependency project
    Kabir Khan Master

    One thing that is taking a lot of time in the wrong order benchmark is in AbstractDependencyItem.resolve(). Since the dependentState is null we end up doing this:

     

       public boolean resolve(Controller controller)
       {
          boolean previous = resolved;
          ControllerContext context;
          if (dependentState == null)
             context = controller.getInstalledContext(iDependOn);
          else
          {
             context = controller.getContext(iDependOn, dependentState);  //<<<< Here
             if (context == null)
             {
                if (ControllerState.INSTALLED.equals(dependentState))
                   context = controller.getInstalledContext(iDependOn);    //<<<< Here
             }
          }
          if (context == null)
          {
             resolved = false;
             ControllerContext unresolvedContext = controller.getContext(iDependOn, null);  //<<<< Here
             if (unresolvedContext != null && ControllerMode.ON_DEMAND.equals(unresolvedContext.getMode()))
             {
                try
                {
                   controller.enableOnDemand(unresolvedContext);
                }
                catch (Throwable ignored)
                {
                   if (log.isTraceEnabled())
                      log.trace("Unexpected error", ignored);
                }
             }
          }
          else
          {
             addDependsOnMe(controller, context);
             resolved = true;
          }
    

      These calls account for about 50% of the time spent.

     

    Changing to:

     

             context = controller.getContext(iDependOn, dependentState);  //<<<< Here
             //if (context == null)
             //{
             //   if (ControllerState.INSTALLED.equals(dependentState))
             //      context = controller.getInstalledContext(iDependOn);    //<<<< Here
             //}
     
    

     

    Gives a perfomance boost to the wrong order test of about 15%. I have committed this.

     

    What I would really like is to be able to is somehow roll the getting of the context and the on demand context into one, something along the lines of

     

       public boolean resolve(Controller controller)
       {
          boolean previous = resolved;
    
          ControllerState state = dependentState == null ? ControllerState.INSTALLED : dependentState;
          ControllerContext context = controller.getContextAtStateOrEnableOnDemand(iDependOn, state);
          
          if (context == null)
          {
             resolved = false;
          }
          else
          {
             addDependsOnMe(controller, context);
             resolved = true;
          }
       }
    
    

     

    That way we only query for the context once instead of twice (three times before my last change)

  • 9. Re: Profiling the dependency project
    Ales Justin Master

    What I would really like is to be able to is somehow roll the getting of the context and the on demand context into one, something along the lines of

     

       public boolean resolve(Controller controller)
       {
          boolean previous = resolved;
     
          ControllerState state = dependentState == null ? ControllerState.INSTALLED : dependentState;
          ControllerContext context = controller.getContextAtStateOrEnableOnDemand(iDependOn, state);
          
          if (context == null)
          {
             resolved = false;
          }
          else
          {
             addDependsOnMe(controller, context);
             resolved = true;
          }
       } 
    

     

    That way we only query for the context once instead of twice (three times before my last change)

    I would add Controller::getContext(name, state, boolean enableOnDemand),

    where previous code would have false for 3rd param.

     

    How much improvement do we see if you add this?

  • 10. Re: Profiling the dependency project
    Kabir Khan Master

    I expect a fair bit, before I started AbstractDependencyInfo.resolve() was taking ~50% of the time being called ~600K times, 95% of this going into calling getInstalledContext() 600k times and getContext() 1200K times.

     

    After my last commit we got rid of a third of the work by getting rid of the 600K calls to getContext.

     

    With this fix all ADInfo.resolve() will do is call getContext() once, so effectively cutting out 2 thirds of what it was doing.

  • 11. Re: Profiling the dependency project
    Kabir Khan Master

    With this change 1000 contexts in the wrong order takes ~2650ms down from ~3500ms in the original AbstractDependencyItem. I'll profile dependency a bit more in isolation tomorrow to look for anything else that is obvious. After that I will start looking at kernel which should be interesting since there are more dependencies on things like MDR.

  • 12. Re: Profiling the dependency project
    Kabir Khan Master

    I tried indexing the dependencies by state since a lot of time is spent iterating over the dependencies to determine the unresolved dependencies, however this had an adverse effect, making it a bit slower

     

    $svn diff

    Index: dependency/src/main/java/org/jboss/dependency/plugins/AbstractDependencyInfo.java

    ===================================================================

    --- dependency/src/main/java/org/jboss/dependency/plugins/AbstractDependencyInfo.java     (revision 100812)

    +++ dependency/src/main/java/org/jboss/dependency/plugins/AbstractDependencyInfo.java     (working copy)

    @@ -24,7 +24,9 @@

    import java.util.Collections;

    import java.util.HashSet;

    import java.util.List;

    +import java.util.Map;

    import java.util.Set;

    +import java.util.concurrent.ConcurrentHashMap;

    import java.util.concurrent.CopyOnWriteArrayList;

    import java.util.concurrent.CopyOnWriteArraySet;

     

    @@ -64,6 +66,10 @@

        /** Whether this is an autowire candidate */

        private boolean autowireCandidate = true;

     

    +   private Map<ControllerState, Set<DependencyItem>> iDependOnByState = new ConcurrentHashMap<ControllerState, Set<DependencyItem>>(5, .75f, 1);

    +  

    +//   private static final ControllerState NULL_CONTROLLER_STATE = ControllerState.newState("Null_AbstractDependencyInfo");

    +

        /**

         * Create an abstract dependency info

         */

    @@ -90,12 +96,34 @@

        public void addIDependOn(DependencyItem dependency)

        {

           iDependOn.add(dependency);

    +     

    +      if (dependency.getWhenRequired() == null)

    +         return;

    +     

    +      Set<DependencyItem> dependOnForState = iDependOnByState.get(dependency.getWhenRequired());

    +      if (dependOnForState == null)

    +      {

    +         dependOnForState = new CopyOnWriteArraySet<DependencyItem>();

    +         Set<DependencyItem> old = iDependOnByState.put(dependency.getWhenRequired(), dependOnForState);

    +         if (old != null)

    +            dependOnForState = old;

    +      }

    +      dependOnForState.add(dependency);

    +     

           flushJBossObjectCache();

        }

     

        public void removeIDependOn(DependencyItem dependency)

        {

           iDependOn.remove(dependency);

    +     

    +      if (dependency.getWhenRequired() == null)

    +         return;

    +

    +      Set<DependencyItem> dependOnForState = iDependOnByState.get(dependency.getWhenRequired());

    +      if (dependOnForState != null)

    +         dependOnForState.remove(dependency);

    +     

           flushJBossObjectCache();

        }

     

    @@ -147,24 +175,61 @@

           if (iDependOn.isEmpty())

              return Collections.emptySet();

     

    +      //Old way

    +//      Set<DependencyItem> result = null;

    +//      for (DependencyItem item : iDependOn)

    +//      {

    +//         if (state == null || state.equals(item.getWhenRequired()))

    +//         {

    +//            if (item.isResolved() == false)

    +//            {

    +//               if (result == null)

    +//                  result = new HashSet<DependencyItem>();

    +//               result.add(item);

    +//            }

    +//         }

    +//      }

    +   

    +      //New way

           Set<DependencyItem> result = null;

    -      for (DependencyItem item : iDependOn)

    +      if (state != null)

           {

    -         if (state == null || state.equals(item.getWhenRequired()))

    +         Set<DependencyItem> dependenciesForState = iDependOnByState.get(state);

    +         if (dependenciesForState != null)

              {

    -            if (item.isResolved() == false)

    +            for (DependencyItem item : dependenciesForState)

                 {

    -               if (result == null)

    -                  result = new HashSet<DependencyItem>();

    -               result.add(item);

    +               if (item.isResolved() == false)

    +               {

    +                  if (result == null)

    +                     result = new HashSet<DependencyItem>();

    +                  result.add(item);

    +               }

                 }

              }

           }

    +      else

    +      {

    +         for (DependencyItem item : iDependOn)

    +         {

    +            if (state == null)

    +            {

    +               if (item.isResolved() == false)

    +               {

    +                  if (result == null)

    +                     result = new HashSet<DependencyItem>();

    +                  result.add(item);

    +               }

    +            }

    +         }

    +      }

    +

    +     

           if (result == null)

              return Collections.emptySet();

           return result;

        }

    -

    +  

        public <T> void addInstallItem(CallbackItem<T> callbackItem)

        {

           installCallbacks.add(callbackItem);

  • 13. Re: Profiling the dependency project
    Kabir Khan Master

    kabir.khan@jboss.com wrote:

     

    I tried indexing the dependencies by state since a lot of time is spent iterating over the dependencies to determine the unresolved dependencies, however this had an adverse effect, making it a bit slower

    The current benchmarks only use one dependency, so it might be faster if there is more than one dependency. I won't add this for now, but will keep it in mind

  • 14. Re: Profiling the dependency project
    Kabir Khan Master

    alesj wrote:

    Can you do a proof check (proof by-design) that this doesn't break the resolve logic.

    At first sight it looks harmless, but we must make sure it's really OK.

    e.g. 2nd resolve would resolve same contexts in both scenarios


    i have tried to find ways to break this, but apart from the point at the end of this post I can't see a way, so I think we're fine. Take this example:

     

    Context A has a DependencyItem{iDependOn=B whenRequired=CONFIGURED dependentState=CONFIGURED}

    Context B has a DependencyItem{iDependOn=C whenRequired=CONFIGURED dependentState=INSTALLED}

     

    We install A and it hangs in INSTANTIATED

    We install B and it hangs in INSTANTIATED

     

    We then install C

     

    Old model:

    Outer loop iteration N:

      inner loop until START

        Find C, move it to INSTALLED

        break out since we incremented contexts

    next outer iteration:

      inner loop until INSTANTIATED:

        Find A, do nothing since B is not in CONFIGURED

        Find B, B has its dependencies resolved and gets moved to CONFIGURED

        break out since we incremented contexts

    next iteration:

      inner loop until INSTANTIATED:

        Find A, A has its dependencies resolved and gets moved to CONFIGURED

        break out since we incremented contexts

    next iteration:

      inner loop until CONFIGURED:

        Find B, B gets moved to CREATE (it is before A in the COWAS for the state)

        Find A, A gets moved to CREATE

        break out since we incremented contexts

    next iteration:

      inner loop until CREATE:

        Find B, B gets moved to START, break out

        Find A, A gets moved to START, break out

        break out since we incremented contexts

    next iteration:

      inner loop until START:

        Find B, B gets moved to INSTALLED, break out

        Find A, A gets moved to INSTALLED, break out

        break out since we incremented contexts

     

    New model:

    C goes through all the states until INSTALLED

    next outer iteration:

      inner loop until INSTANTIATED:

        Find A, A has its dependencies resolved and gets moved to CONFIGURED

      next inner loop CONFIGURED

        Find A, A gets moved to CREATE

      next inner loop CREATE

        Find A, A gets moved to START

      next inner loop START

        Find A, A gets moved to INSTALLED

    next outer iteration

      inner loop until INSTANTIATED:

        Find A, do nothing since B is not in CONFIGURED

        Find A, A has its dependencies resolved and gets moved to CONFIGURED

      next inner loop CONFIGURED

        Find A, A gets moved to CREATE

      next inner loop CREATE

        Find A, A gets moved to START

      next inner loop START

        Find A, A gets moved to INSTALLED

     

    I was talking about changing COWAS for contextsByState earlier, but this exercise has convinced me that it is needed due to the fact that its iterator will return contexts in the order they were added.

     

    So in both cases C enters CONFIGURED, CREATE, START and INSTALLED before B, and similarly B enters those states before A. This is as it should be at least from the old ServiceController training notes: if a context has a dependency then the context we depend on will be created by the time we are created, and the context we depend on will be started by the time we are started.

     

    The only way I can think of breaking this is if B had a DependencyItem{iDependOn=D whenRequired=CREATE dependentState=INSTALLED}, in which case B would hang in CONFIGURED case until D is installed, meaning A would enter CREATE, START, INSTALLED before B, but that is true in both models.

1 2 Previous Next