Bug 575450 - Performance regression in getServiceReference via PackageSource.isServiceAssignableTo
Summary: Performance regression in getServiceReference via PackageSource.isServiceAssi...
Status: CLOSED WONTFIX
Alias: None
Product: Equinox
Classification: Eclipse Project
Component: Framework (show other bugs)
Version: 4.17   Edit
Hardware: PC All
: P3 normal with 1 vote (vote)
Target Milestone: ---   Edit
Assignee: equinox.framework-inbox CLA
QA Contact:
URL:
Whiteboard: stalebug
Keywords: performance, regression
Depends on:
Blocks:
 
Reported: 2021-08-17 05:55 EDT by Christian Dietrich CLA
Modified: 2023-09-19 08:41 EDT (History)
4 users (show)

See Also:


Attachments
Yourkit Before (197.50 KB, image/png)
2021-08-17 05:55 EDT, Christian Dietrich CLA
no flags Details
Yourkit After (212.94 KB, image/png)
2021-08-17 05:55 EDT, Christian Dietrich CLA
no flags Details
Simple reproducer (11.53 KB, application/zip)
2021-08-17 10:11 EDT, Christian Dietrich CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Christian Dietrich CLA 2021-08-17 05:55:26 EDT
Created attachment 286956 [details]
Yourkit Before

We recently updated from Eclipse 4.15 to Eclipse 4.21
When performance measuring our application we saw a regression in our code.

We currently do a lot of calls into 
org.osgi.framework.BundleContext.getServiceReference(Class<S>)
+
org.osgi.framework.BundleContext.getService(ServiceReference<S>)
 
With 4.15 it was no problem to call it 100k of times but with 4.21 it is a lot slower.

As you can see in the attached yourkit the majority of the time is spent in 
PackageSource.isServiceAssignableTo
which seems to have changed in 4.17

Is then worsened performance intentional/non avoidable on osgi side
(we will check if we can avoid so many calls on our side too)
Comment 1 Christian Dietrich CLA 2021-08-17 05:55:48 EDT
Created attachment 286957 [details]
Yourkit After
Comment 2 Andrey Loskutov CLA 2021-08-17 07:46:42 EDT
Probably regression from bug 562980.
Comment 3 Thomas Watson CLA 2021-08-17 09:08:13 EDT
Does your scenario involve lookup of services from private (unexported) packages?  If not is the calling/consuming bundle wired (import-package or require-bundle) to an exporter of the package the service is included in.  If I recall correctly the changes from bug 562980 were mostly to deal with consistency checks when dealing with private packages or consumers not wired to a package in which case we needed to do extra work to make sure we don't have a clash where the registering bundle and the consuming bundle both have a version of the service class in their class space.
Comment 4 Thomas Watson CLA 2021-08-17 09:17:10 EDT
(In reply to Thomas Watson from comment #3)
> Does your scenario involve lookup of services from private (unexported)
> packages?  If not is the calling/consuming bundle wired (import-package or
> require-bundle) to an exporter of the package the service is included in. 
> If I recall correctly the changes from bug 562980 were mostly to deal with
> consistency checks when dealing with private packages or consumers not wired
> to a package in which case we needed to do extra work to make sure we don't
> have a clash where the registering bundle and the consuming bundle both have
> a version of the service class in their class space.

If we understand the scenario that causes the issue we could consider a cache for the service registration that records the assignability of the registration per bundle.  I suspect such a cache would need to be invalidated any time the wiring changed at the container level.  Such a cache would need to flush the assignability any time a bundle is unresolved or uninstalled.  The tricky part is dynamic imports.  There is no good indicator outside of the container to know that a bundle has been dynamically wired to a new package with DynamicImport-Package.

But before that is considered, could you provide a small case that exhibits the issue so we can evaluate the cause better?
Comment 5 Christian Dietrich CLA 2021-08-17 09:20:21 EDT
no. the package with the service implementation is not exported.
isnt this the normal osgi service pattern?
Comment 6 Thomas Watson CLA 2021-08-17 09:29:53 EDT
(In reply to Christian Dietrich from comment #5)
> no. the package with the service implementation is not exported.
> isnt this the normal osgi service pattern?

No, here I mean the package for which the service contract class/interface is located and used to register the service (e.g. org.my.service.contract).  Not the actual implementation package (e.g. org.my.implementation.pkg)
Comment 7 Christian Dietrich CLA 2021-08-17 09:52:24 EDT
of course(tm) i am fighting to get a reproducible example that is also slow.
Comment 8 Christian Dietrich CLA 2021-08-17 10:11:24 EDT
Created attachment 286959 [details]
Simple reproducer

please find a simple reproducer attached
on my machine i see 2 vs 11s. (measured without yourkit)
Comment 9 Thomas Watson CLA 2021-08-17 10:15:14 EDT
For reference this is the TCK tests added for OSGi for this clarification:

https://github.com/osgi/osgi/blob/r8-core-final/org.osgi.test.cases.framework/src/org/osgi/test/cases/framework/junit/classloading/ClassLoadingTests.java#L297-L476
Comment 10 Christian Dietrich CLA 2021-08-17 10:39:32 EDT
interestingly. 
if the MyUtil class has the interface bundle on classpath

Require-Bundle: org.eclipse.core.runtime,
 mys;bundle-version="1.0.0"

times are much better again
Comment 11 Thomas Watson CLA 2021-08-17 11:46:31 EDT
(In reply to Christian Dietrich from comment #8)
> Created attachment 286959 [details]
> Simple reproducer
> 
> please find a simple reproducer attached
> on my machine i see 2 vs 11s. (measured without yourkit)

Thanks, that testcase does exercise the private package check.  The use of MyUtil to get the service causes the myc bundle context to be used to get the service on behalf of another bundle.  the myc bundle does not import or require the package myservice so the framework is forced to try and load the class from the myc bundle before allowing its bundle context to "see" the service.  The extra check to the class loader for myc is contributing to the full slowdown here.  To prove that if you add mys to the Require-Bundle header of myc it drastically improves the performance 5x on my machine.

But I will point out that the pattern can be improved performance wise and for correctness by using org.eclipse.core.runtime.ServiceCaller<IMyService> with something like this:

package myt;

import org.eclipse.core.runtime.ServiceCaller;
import org.junit.Test;

import myservice.IMyService;

public class MyTest {	
	static final ServiceCaller<IMyService> serviceCaller = new ServiceCaller<>(MyTest.class, IMyService.class);
	@Test
	public void testIt() {
		long start = System.currentTimeMillis();
		for (int i=0; i < 1_000_000;i++) {
			serviceCaller.current().get();
			//MyUtil.getService(IMyService.class);
		}
		long end = System.currentTimeMillis();
		System.out.println((end-start)/1000);
	}

}

That brings the recorded time down to zero for me.  ServiceCaller does require that your consuming bundle be started which required that I add Bundle-ActivationPolicy: lazy to the myt bundle.  I recommend you use something like ServiceCaller or ServiceTracker to cache service lookups and to ensure the correct BundleContext is being used to get the service or use something like Declarative Services for service consumption.
Comment 12 Eclipse Genie CLA 2023-09-19 08:41:27 EDT
This bug hasn't had any activity in quite some time. Maybe the problem got resolved, was a duplicate of something else, or became less pressing for some reason - or maybe it's still relevant but just hasn't been looked at yet. As such, we're closing this bug.

If you have further information on the current state of the bug, please add it and reopen this bug. The information can be, for example, that the problem still occurs, that you still want the feature, that more information is needed, or that the bug is (for whatever reason) no longer relevant.

--
The automated Eclipse Genie.