Home » Eclipse Projects » Equinox » Equinox performance with many DS factory components(Equinox takes O(n) time to create one new instance of a DS factory component)
|Equinox performance with many DS factory components [message #1485992]
||Mon, 24 November 2014 18:31
| Colin Williams
Registered: November 2014
TLDR: We launch 3 Declarative Services factory components for each "user" defined in the system. Equinox seems to require O(n) time to enter the activate methods of the factory components, so at 600 users (thus, ~1800 factory components for the users system), it takes Equinox almost half a second to enter the activate method of the last components after ComponentFactory.newInstance is called.
We are using Equinox for a fairly large application, and are trying to track down performance issues. I would like your assistance determining whether I am doing something wrong, Equinox has a bug, or Equinox simply can't handle my use case (in which case suggestions for alternative ways to accomplish the same thing would be appreciated).
Here's the set up: we're using Equinox embedded in Jetty using the servlet bridge. Within the Equinox instance, we have a component that reads configuration and creates a number of User objects, one for each user configured in the system. In order to allow other bundles to easily add functionality to each user, we use factory components. For each user in the system, the main user component fires up a ServiceTracker to search for components defined with a particular factory specified.
Next, any time a new service is registered with the configured ServiceTrackerCustomizer, it constructs a properties instance with a reference to the user that this factory should be used for, and appropriate configuration information. It then calls newInstance(props) on the ComponentFactory provided with the ServiceReference. What we are finding is that newInstance takes an increasingly long time (O(n)) to run with each invocation, even discounting the time it takes the factory to actually run its activate method. More details on the testing methods below. This leads to a situation where the more users are configured, the longer it takes the user component to fully start up, on the order of n^2 (since it takes O(n) time for each component to start up, and you have n users, each with a component). Exact details on times below as well.
Here's what I have considered as possibilities:
1. An error in our use of the OSGi APIs and Equinox. This is entirely possible, but the evidence seems to point away from it.
2. Equinox has a bug that leads to O(n) component configuration times when using factories.
3. The system that we are using to easily add functionality to a user (1 factory instance per user) is not a good thing to do with OSGi/Equinox, and we should rethink our approach. If this is the case, I'm curious what other approaches might be better for this situation.
4. Our sampling methods are so inaccurate that they're not providing meaningful information to us.
Testing methods: For all of the below tests, the application was run on a dual-core mobile i7 (i7-2640M @ 2.80GHz), with 16GB of RAM.
First, while using JVisualVM to profile our application startup, we noticed that above a few hundred users, the method 'org.eclipse.Equinox.internal.ds.Reference.selectProviders()' was consuming a disproportionately large amount of CPU time. The process of profiling was to place a breakpoint at our main() method, run the application in debug, attach JVisualVM to the process, start "Sampling" CPU profiling on the JVisualVM instance, and then allow the application execution to continue. I'm aware that both debugging and attaching JVisualVM to the process will slow it down, but the performance issues are apparent without either involved. The times for selectProvider in this table are the JVisualVM report for "Self Time" for the selectProvider method. The Time to Start is the approximate amount of time required to start the factory components for the users (from the time the first one began starting until the last one finished).
Users selectProviders Time to start
----- --------------- -------------
100 1,741 ms (3.9%) 00:05
200 11,954 ms (10.6%) 00:23
400 27,636 ms (36.9%) 01:54
600 35,341 ms (54.8%) 05:33
Next, I wanted to confirm that it was Equinox with the issue and not our own code. To do so, I set up a timer system using System.currentTimeMillis. I'm aware this is not a particularly accurating timing system since it doesn't measure CPU time, but with the results, I don't believe that matters. I would start the timer immediately before the call to ComponentFactory.newInstance() and stop the timer as the first line of the component's activate method. By this, I was hoping to capture only the time spent in Equinox's methods, and not the time in our own startup method. The results were pretty clear, if I'm understanding everything correctly.
We currently have two of these factory components defined, which will each start up one instance per user. The first pulls in two other services, and the second pulls in 4 other services. Additionally, the second component itself opens a service tracker to pull in an instance of another factory. We have observed that this piece of code also exhibits the same behavior regarding linear increases in time required for each instance.
The first (simpler) component is more difficult to observe the behavior with, but it can be observed. With 600 users defined, the first few instances take 2-3ms to enter the activate method, and the last few instances take 40-45ms to enter the activate method. The increase in time required is approximately linear when averaged.
The second component exhibits the behavior in a much more dramatic fashion. With 600 users defined, the first few instances take 50-60ms to enter the activate method, and the last few instances take 450-470ms to enter the activate method. Additionally, the activate method itself takes a similar amount of time to run, due to the aforementioned launch of another factory component.
As a side note, at 400 users, Equinox begins throwing this error:
!ENTRY org.eclipse.Equinox.ds 2 0 2014-11-22 14:25:37.105
!MESSAGE [SCR] Enabling components of bundle <bundlename> did not complete in 30000 ms
In this case, <bundlename> is the bundle containing the second factory component (which also contains the third). Despite these errors, though, it does continue launching the components for as long as it takes.
Current Time: Sat Nov 17 10:42:51 GMT 2018
Powered by FUDForum
. Page generated in 0.02323 seconds