[
https://issues.apache.org/jira/browse/FELIX-6863?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Stefan Tataru updated FELIX-6863:
---------------------------------
Description:
h3. *Problem*
[ResourceImpl.hashCode|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L131]
recomputes [Objects.hash(caps,
reqs)|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L132]
on every invocation: both lists are walked and {{hashCode}} is called on every
capability and requirement in them. In Karaf,
[ResourceImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L34]
instances are used as keys in hash-based collections. For example,
[SubsystemResolveContext|https://github.com/apache/karaf/blob/6e6f9ae0c009eb0e0bc935acc5869d952c24b109/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L69]
maintains a [HashMap<Resource,
Subsystem>|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L76]
into which
[ResourceImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L34]
instances are inserted: [ResourceImpl wrapped = new
ResourceImpl()|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L381]
→ [resToSub.put(wrapped,
subsystem)|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L392].
The same map is subsequently queried via
[resToSub.get(resource)|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L268]
from:
[SubsystemResolveContext.getRegion|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L271]
→
[SubsystemResolveContext.getSubsystem|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L267].
For non-null keys, {{HashMap}} calls the key's {{hashCode}} on every {{put}}
and {{get}}, causing
[ResourceImpl.hashCode|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L131]
to be invoked on every such operation. On its own, this is just repeated work,
but its cost can vary a lot between JVM runs, depending on how the JIT compiles
the {{hashCode}} calls involved.
h3. *Impact*
I'm not very familiar with HotSpot's JIT compiler. I ran some experiments, and
an LLM helped me analyze the results, particularly the JIT behavior described
in the paragraph below. Please correct me if I got anything wrong.
[Objects.hash(caps,
reqs)|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L132]
ends up in {{ArrayList.hashCode}} for each of the two lists.
{{ArrayList.hashCode}} calls {{ArrayList.hashCodeRange}}, which loops over the
elements and calls {{e.hashCode}}.
[CapabilityImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/CapabilityImpl.java#L32]
and
[RequirementImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/RequirementImpl.java#L31]
don’t override {{hashCode}}, so each of those calls is an {{Object.hashCode}}
call. The JIT decides how to compile the {{e.hashCode}} call inside
{{ArrayList.hashCodeRange}} from the classes it saw there while the JVM was
starting. If it mostly saw one unrelated class, the
[CapabilityImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/CapabilityImpl.java#L32]
and
[RequirementImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/RequirementImpl.java#L31]
elements end up on a slower path: a real call into the native
{{Object.hashCode}} for every element, instead of a few inlined instructions
that read the hash from the object header. In my runs it could stay like that
for as long as the JVM was running.
On my machine, the steps below consistently reproduce this worst case:
{{feature:install}} and {{feature:uninstall}} take ~4 seconds before a JVM
restart and ~22 seconds after, with no change in what is installed.
h3. *Steps to reproduce*
# Download and unzip
[apache-karaf-4.4.11|https://archive.apache.org/dist/karaf/4.4.11/apache-karaf-4.4.11.zip]
# Enable the {{karaf}} user for {{bin/client}}. In
{{apache-karaf-4.4.11/etc/users.properties}}, uncomment these two lines:
{code:none}
karaf = karaf,g:admingroup
g\:admingroup = group,admin,manager,viewer,systembundles,ssh
{code}
# Start Karaf and, in the Karaf console, add the Camel 4.18.2 features
repository:
{code:bash}
feature:repo-add mvn:org.apache.camel.karaf/apache-camel/4.18.2/xml/features
{code}
# Install the Camel features below. This step is required to pollute the JIT
profile at JVM start. According to the LLM's analysis, the pollution comes
mainly from Import-Package entries that have a version: a fresh Karaf
installation has too few of them, and the generated dummy app KARs have none.
On my machine, the ~200 bundles these features add were enough:
{code:bash}
for f in camel camel-core camel-blueprint camel-spring camel-activemq
camel-amqp camel-bean-validator camel-bindy camel-caffeine camel-csv camel-cxf
camel-ftp camel-http camel-jackson camel-jaxb camel-jms camel-jsonpath
camel-kafka camel-mail camel-netty camel-netty-http camel-quartz camel-sql
camel-stream camel-xpath camel-xslt; do
./apache-karaf-4.4.11/bin/client -u karaf -p karaf "feature:install -r $f" ||
echo "FAILED: $f"
done
{code}
# Generate dummy app KAR files with the attached *generate_repro.py* script.
Use {{{}count 1{}}} to reproduce the problem, or {{{}count 300{}}} to amplify
it. The generated KARs from a single run can all be installed side by side:
{code:bash}
python3 generate_repro.py --count 1 --out repro-kars-1
python3 generate_repro.py --count 300 --out repro-kars-300
{code}
# Install all the generated KARs, for example by copying them to
{{apache-karaf-4.4.11/deploy/}}:
{code:bash}
cp repro-kars-300/* apache-karaf-4.4.11/deploy/
{code}
# Wait until all the generated KARs are fully installed. In the Karaf console,
{{kar:list | wc}} should return the number of generated KARs + 2, and all
installed bundles should be in the state {{Active}}:
{code:bash}
kar:list | wc
{code}
# (Optional) Check the {{feature:install}} and {{feature:uninstall}}
performance manually, for example by installing another KAR or uninstalling an
existing one. A quick way to time it without the script:
{code:bash}
time ./apache-karaf-4.4.11/bin/client -u karaf -p karaf "feature:uninstall -t
-r repro-app-001"
{code}
*(-t only simulates the uninstall, so the command can be repeated)*
# Start a JFR recording, then measure {{feature:uninstall}} with the attached
*measure_feature_uninstall.py* script while the recording is running. Run both
commands together, so the measurement starts right after the recording does:
{code:bash}
jcmd $(cat ./apache-karaf-4.4.11/karaf.pid) JFR.start duration=120s
settings=profile jdk.ExecutionSample#period=10ms
jdk.NativeMethodSample#period=10ms
filename=default_karaf_before_jvm_restart.jfr && \
python3 measure_feature_uninstall.py --client ./apache-karaf-4.4.11/bin/client
--command "feature:uninstall -t -r repro-app-001" --title "before restart"
--runs 10
{code}
# Wait for the JFR recording to finish
# Restart Karaf without cleaning the {{data}} folder, and wait until all
bundles are in the state {{Active}}
# (Optional) Check the {{feature:install}} and {{feature:uninstall}}
performance manually as in step *8*
# Repeat step *9* with:
{code:bash}
jcmd $(cat ./apache-karaf-4.4.11/karaf.pid) JFR.start duration=120s
settings=profile jdk.ExecutionSample#period=10ms
jdk.NativeMethodSample#period=10ms filename=default_karaf_after_jvm_restart.jfr
&& \
python3 measure_feature_uninstall.py --client ./apache-karaf-4.4.11/bin/client
--command "feature:uninstall -t -r repro-app-001" --title "after restart"
--runs 10
{code}
# Wait for the recording to finish
What to look for in the recordings
- {*}default_karaf_before_jvm_restart.jfr:{*} shows
{{ArrayList.hashCodeRange}} as the top Java method:
!image-2026-10-01-20-31-40-225.png!
- {*}default_karaf_after_jvm_restart.jfr:{*} {{{}ArrayList.hashCodeRange{}}}
is gone from the Java samples (and from JMC's Method Profiling page). The
features thread now spends most of its time inside a native method, which JFR
records as a separate event, {{jdk.NativeMethodSample}} (JMC: Event Browser →
Java Application → Method Profiling Sample Native). {{jfr view native-methods
after_restart.jfr}} lists {{{}java.lang.Object.hashCode{}}}; the other entries
there are idle I/O threads. In each of those samples,
{{java.util.ArrayList.hashCodeRange}} is the frame right below
{{java.lang.Object.hashCode;}}
h3. *Proposal*
One way to fix this is to cache the result of
[ResourceImpl.hashCode|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L131]
and only recompute it when the [List<Capability>
caps|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L36]
or\{{ }}[List<Requirement>
reqs|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L37]
change.
The fix can be tested in either of the following ways, before step {{2}} from
the "{*}Steps to reproduce{*}":
* Replace
{{./apache-karaf-4.4.11/system/org/apache/karaf/features/org.apache.karaf.features.core/4.4.11/org.apache.karaf.features.core-4.4.11.jar}}
with the attached jar.
* Build {{org.apache.felix:org.apache.felix.utils}} locally from the proposed
PR, then rebuild
[org.apache.karaf.features:org.apache.karaf.features.core|https://github.com/apache/karaf/blob/karaf-4.4.11/features/core/pom.xml]
against it, and replace
{{./apache-karaf-4.4.11/system/org/apache/karaf/features/org.apache.karaf.features.core/4.4.11/org.apache.karaf.features.core-4.4.11.jar}}
|Kars installed|feature:uninstall before restart|after restart|after restart,
with the fix|
|1|1.3 s|2.3 s|1.4 s|
|300|~4 s|~22 s|~3.5 s|
was:
h3. *Problem*
[ResourceImpl.hashCode|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L131]
recomputes [Objects.hash(caps,
reqs)|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L132]
on every invocation: both lists are walked and {{hashCode}} is called on every
capability and requirement in them. In Karaf,
[ResourceImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L34]
instances are used as keys in hash-based collections. For example,
[SubsystemResolveContext|https://github.com/apache/karaf/blob/6e6f9ae0c009eb0e0bc935acc5869d952c24b109/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L69]
maintains a [HashMap<Resource,
Subsystem>|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L76]
into which
[ResourceImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L34]
instances are inserted: [ResourceImpl wrapped = new
ResourceImpl()|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L381]
→ [resToSub.put(wrapped,
subsystem)|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L392].
The same map is subsequently queried via
[resToSub.get(resource)|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L268]
from:
[SubsystemResolveContext.getRegion|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L271]
→
[SubsystemResolveContext.getSubsystem|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L267].
For non-null keys, {{HashMap}} calls the key's {{hashCode}} on every {{put}}
and {{{}get{}}}, causing
[ResourceImpl.hashCode|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L131]
to be invoked on every such operation. On its own, this is just repeated work,
but its cost can vary a lot between JVM runs, depending on how the JIT compiles
the {{hashCode}} calls involved.
h3. *Impact*
I'm not very familiar with HotSpot's JIT compiler. I ran some experiments, and
an LLM helped me analyze the results, particularly the JIT behavior described
in the paragraph below. Please correct me if I got anything wrong.
[Objects.hash(caps,
reqs)|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L132]
ends up in {{ArrayList.hashCode}} for each of the two lists.
{{ArrayList.hashCode}} calls {{{}ArrayList.hashCodeRange{}}}, which loops over
the elements and calls {{{}e.hashCode{}}}.
[CapabilityImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/CapabilityImpl.java#L32]
and
[RequirementImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/RequirementImpl.java#L31]
don’t override {{{}hashCode{}}}, so each of those calls is an
{{Object.hashCode}} call. The JIT decides how to compile the {{e.hashCode}}
call inside {{ArrayList.hashCodeRange}} from the classes it saw there while the
JVM was starting. If it mostly saw one unrelated class, the
[CapabilityImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/CapabilityImpl.java#L32]
and
[RequirementImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/RequirementImpl.java#L31]
elements end up on a slower path: a real call into the native
{{Object.hashCode}} for every element, instead of a few inlined instructions
that read the hash from the object header. In my runs it could stay like that
for as long as the JVM was running.
On my machine, the steps below consistently reproduce this worst case:
{{feature:install}} and {{feature:uninstall}} take ~4 seconds before a JVM
restart and ~22 seconds after, with no change in what is installed.
h3. *Steps to reproduce*
# Download and unzip
[apache-karaf-4.4.11|https://archive.apache.org/dist/karaf/4.4.11/apache-karaf-4.4.11.zip]
# Enable the {{karaf}} user for {{{}bin/client{}}}. In
{{{}apache-karaf-4.4.11/etc/users.properties{}}}, uncomment these two lines:
{code:none}
karaf = karaf,g:admingroup
g\:admingroup = group,admin,manager,viewer,systembundles,ssh
{code}
# Start Karaf and, in the Karaf console, add the Camel 4.18.2 features
repository:
{code:bash}
feature:repo-add mvn:org.apache.camel.karaf/apache-camel/4.18.2/xml/features
{code}
# Install the Camel features below. This step is required to pollute the JIT
profile at JVM start. According to the LLM's analysis, the pollution comes
mainly from Import-Package entries that have a version: a fresh Karaf
installation has too few of them, and the generated dummy app KARs have none.
On my machine, the ~200 bundles these features add were enough:
{code:bash}
for f in camel camel-core camel-blueprint camel-spring camel-activemq
camel-amqp camel-bean-validator camel-bindy camel-caffeine camel-csv camel-cxf
camel-ftp camel-http camel-jackson camel-jaxb camel-jms camel-jsonpath
camel-kafka camel-mail camel-netty camel-netty-http camel-quartz camel-sql
camel-stream camel-xpath camel-xslt; do
./apache-karaf-4.4.11/bin/client -u karaf -p karaf "feature:install -r $f" ||
echo "FAILED: $f"
done
{code}
# Generate dummy app KAR files with the attached *generate_repro.py* script.
Use {{count 1}} to reproduce the problem, or {{count 300}} to amplify it. The
generated KARs from a single run can all be installed side by side:
{code:bash}
python3 generate_repro.py --count 1 --out repro-kars-1
python3 generate_repro.py --count 300 --out repro-kars-300
{code}
# Install all the generated KARs, for example by copying them to
{{{}apache-karaf-4.4.11/deploy/{}}}:
{code:bash}
cp repro-kars-300/* apache-karaf-4.4.11/deploy/
{code}
# Wait until all the generated KARs are fully installed. In the Karaf console,
{{kar:list | wc}} should return the number of generated KARs + 2, and all
installed bundles should be in the state {{{}Active{}}}:
{code:bash}
kar:list | wc
{code}
# (Optional) Check the {{feature:install}} and {{feature:uninstall}}
performance manually, for example by installing another KAR or uninstalling an
existing one. A quick way to time it without the script:
{code:bash}
time ./apache-karaf-4.4.11/bin/client -u karaf -p karaf "feature:uninstall -t
-r repro-app-001"
{code}
*(-t only simulates the uninstall, so the command can be repeated)*
# Start a JFR recording, then measure {{feature:uninstall}} with the attached
*measure_feature_uninstall.py* script while the recording is running. Run both
commands together, so the measurement starts right after the recording does:
{code:bash}
jcmd $(cat ./apache-karaf-4.4.11/karaf.pid) JFR.start duration=120s
settings=profile jdk.ExecutionSample#period=10ms
jdk.NativeMethodSample#period=10ms
filename=default_karaf_before_jvm_restart.jfr && \
python3 measure_feature_uninstall.py --client ./apache-karaf-4.4.11/bin/client
--command "feature:uninstall -t -r repro-app-001" --title "before restart"
--runs 10
{code}
# Wait for the JFR recording to finish
# Restart Karaf without cleaning the {{data}} folder, and wait until all
bundles are in the state {{Active}}
# (Optional) Check the {{feature:install}} and {{feature:uninstall}}
performance manually as in step *8*
# Repeat step *9* with:
{code:bash}
jcmd $(cat ./apache-karaf-4.4.11/karaf.pid) JFR.start duration=120s
settings=profile jdk.ExecutionSample#period=10ms
jdk.NativeMethodSample#period=10ms filename=default_karaf_after_jvm_restart.jfr
&& \
python3 measure_feature_uninstall.py --client ./apache-karaf-4.4.11/bin/client
--command "feature:uninstall -t -r repro-app-001" --title "after restart"
--runs 10
{code}
# Wait for the recording to finish
What to look for in the recordings
- *default_karaf_before_jvm_restart.jfr:* shows {{ArrayList.hashCodeRange}} as
the top Java method:
!image-2026-10-01-20-31-40-225.png!
- *default_karaf_after_jvm_restart.jfr:*
h3. *Proposal*
One way to fix this is to cache the result of
[ResourceImpl.hashCode|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L131]
and only recompute it when the [List<Capability>
caps|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L36]
or\{{ }}[List<Requirement>
reqs|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L37]
change.
The fix can be tested in either of the following ways, before step {{2}} from
the "{*}Steps to reproduce{*}":
* Replace
{{./apache-karaf-4.4.11/system/org/apache/karaf/features/org.apache.karaf.features.core/4.4.11/org.apache.karaf.features.core-4.4.11.jar}}
with the attached jar.
* Build {{org.apache.felix:org.apache.felix.utils}} locally from the proposed
PR, then rebuild
[org.apache.karaf.features:org.apache.karaf.features.core|https://github.com/apache/karaf/blob/karaf-4.4.11/features/core/pom.xml]
against it, and replace
{{./apache-karaf-4.4.11/system/org/apache/karaf/features/org.apache.karaf.features.core/4.4.11/org.apache.karaf.features.core-4.4.11.jar}}
|Kars installed|feature:uninstall before restart|after restart|after restart,
with the fix|
|1|1.3 s|2.3 s|1.4 s|
|300|~4 s|~22 s|~3.5 s|
> ResourceImpl.hashCode is not cached and can make Karaf feature
> install/uninstall much slower after a JVM restart
> ----------------------------------------------------------------------------------------------------------------
>
> Key: FELIX-6863
> URL: https://issues.apache.org/jira/browse/FELIX-6863
> Project: Felix
> Issue Type: Improvement
> Components: Utils
> Affects Versions: utils-1.11.8
> Environment: Apache Karaf 4.4.11 (binary distribution)
> OpenJDK 64-Bit Server VM, Java 21.0.7
> OS: macOS 26.6.2, Apple Silicon, aarch64
> Reporter: Stefan Tataru
> Priority: Major
> Labels: performance
> Attachments: default_karaf_after_jvm_restart-1.jfr,
> default_karaf_before_jvm_restart.jfr,
> feature-uninstall-measurements_300_kars.md, generate_repro.py,
> image-2026-10-01-20-31-40-225.png, measure_feature_uninstall.py,
> org.apache.karaf.features.core-4.4.11.jar
>
>
> h3. *Problem*
> [ResourceImpl.hashCode|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L131]
> recomputes [Objects.hash(caps,
> reqs)|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L132]
> on every invocation: both lists are walked and {{hashCode}} is called on
> every capability and requirement in them. In Karaf,
> [ResourceImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L34]
> instances are used as keys in hash-based collections. For example,
> [SubsystemResolveContext|https://github.com/apache/karaf/blob/6e6f9ae0c009eb0e0bc935acc5869d952c24b109/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L69]
> maintains a [HashMap<Resource,
> Subsystem>|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L76]
> into which
> [ResourceImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L34]
> instances are inserted: [ResourceImpl wrapped = new
> ResourceImpl()|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L381]
> → [resToSub.put(wrapped,
> subsystem)|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L392].
> The same map is subsequently queried via
> [resToSub.get(resource)|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L268]
> from:
> [SubsystemResolveContext.getRegion|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L271]
> →
> [SubsystemResolveContext.getSubsystem|https://github.com/apache/karaf/blob/dfdbc66d42b0e2ab490cce063a25494127d15b13/features/core/src/main/java/org/apache/karaf/features/internal/region/SubsystemResolveContext.java#L267].
> For non-null keys, {{HashMap}} calls the key's {{hashCode}} on every {{put}}
> and {{get}}, causing
> [ResourceImpl.hashCode|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L131]
> to be invoked on every such operation. On its own, this is just repeated
> work, but its cost can vary a lot between JVM runs, depending on how the JIT
> compiles the {{hashCode}} calls involved.
> h3. *Impact*
> I'm not very familiar with HotSpot's JIT compiler. I ran some experiments,
> and an LLM helped me analyze the results, particularly the JIT behavior
> described in the paragraph below. Please correct me if I got anything wrong.
> [Objects.hash(caps,
> reqs)|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L132]
> ends up in {{ArrayList.hashCode}} for each of the two lists.
> {{ArrayList.hashCode}} calls {{ArrayList.hashCodeRange}}, which loops over
> the elements and calls {{e.hashCode}}.
> [CapabilityImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/CapabilityImpl.java#L32]
> and
> [RequirementImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/RequirementImpl.java#L31]
> don’t override {{hashCode}}, so each of those calls is an
> {{Object.hashCode}} call. The JIT decides how to compile the {{e.hashCode}}
> call inside {{ArrayList.hashCodeRange}} from the classes it saw there while
> the JVM was starting. If it mostly saw one unrelated class, the
> [CapabilityImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/CapabilityImpl.java#L32]
> and
> [RequirementImpl|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/RequirementImpl.java#L31]
> elements end up on a slower path: a real call into the native
> {{Object.hashCode}} for every element, instead of a few inlined instructions
> that read the hash from the object header. In my runs it could stay like that
> for as long as the JVM was running.
> On my machine, the steps below consistently reproduce this worst case:
> {{feature:install}} and {{feature:uninstall}} take ~4 seconds before a JVM
> restart and ~22 seconds after, with no change in what is installed.
> h3. *Steps to reproduce*
> # Download and unzip
> [apache-karaf-4.4.11|https://archive.apache.org/dist/karaf/4.4.11/apache-karaf-4.4.11.zip]
> # Enable the {{karaf}} user for {{bin/client}}. In
> {{apache-karaf-4.4.11/etc/users.properties}}, uncomment these two lines:
> {code:none}
> karaf = karaf,g:admingroup
> g\:admingroup = group,admin,manager,viewer,systembundles,ssh
> {code}
> # Start Karaf and, in the Karaf console, add the Camel 4.18.2 features
> repository:
> {code:bash}
> feature:repo-add mvn:org.apache.camel.karaf/apache-camel/4.18.2/xml/features
> {code}
> # Install the Camel features below. This step is required to pollute the JIT
> profile at JVM start. According to the LLM's analysis, the pollution comes
> mainly from Import-Package entries that have a version: a fresh Karaf
> installation has too few of them, and the generated dummy app KARs have none.
> On my machine, the ~200 bundles these features add were enough:
> {code:bash}
> for f in camel camel-core camel-blueprint camel-spring camel-activemq
> camel-amqp camel-bean-validator camel-bindy camel-caffeine camel-csv
> camel-cxf camel-ftp camel-http camel-jackson camel-jaxb camel-jms
> camel-jsonpath camel-kafka camel-mail camel-netty camel-netty-http
> camel-quartz camel-sql camel-stream camel-xpath camel-xslt; do
> ./apache-karaf-4.4.11/bin/client -u karaf -p karaf "feature:install -r $f"
> || echo "FAILED: $f"
> done
> {code}
> # Generate dummy app KAR files with the attached *generate_repro.py* script.
> Use {{{}count 1{}}} to reproduce the problem, or {{{}count 300{}}} to amplify
> it. The generated KARs from a single run can all be installed side by side:
> {code:bash}
> python3 generate_repro.py --count 1 --out repro-kars-1
> python3 generate_repro.py --count 300 --out repro-kars-300
> {code}
> # Install all the generated KARs, for example by copying them to
> {{apache-karaf-4.4.11/deploy/}}:
> {code:bash}
> cp repro-kars-300/* apache-karaf-4.4.11/deploy/
> {code}
> # Wait until all the generated KARs are fully installed. In the Karaf
> console, {{kar:list | wc}} should return the number of generated KARs + 2,
> and all installed bundles should be in the state {{Active}}:
> {code:bash}
> kar:list | wc
> {code}
> # (Optional) Check the {{feature:install}} and {{feature:uninstall}}
> performance manually, for example by installing another KAR or uninstalling
> an existing one. A quick way to time it without the script:
> {code:bash}
> time ./apache-karaf-4.4.11/bin/client -u karaf -p karaf "feature:uninstall -t
> -r repro-app-001"
> {code}
> *(-t only simulates the uninstall, so the command can be repeated)*
> # Start a JFR recording, then measure {{feature:uninstall}} with the
> attached *measure_feature_uninstall.py* script while the recording is
> running. Run both commands together, so the measurement starts right after
> the recording does:
> {code:bash}
> jcmd $(cat ./apache-karaf-4.4.11/karaf.pid) JFR.start duration=120s
> settings=profile jdk.ExecutionSample#period=10ms
> jdk.NativeMethodSample#period=10ms
> filename=default_karaf_before_jvm_restart.jfr && \
> python3 measure_feature_uninstall.py --client
> ./apache-karaf-4.4.11/bin/client --command "feature:uninstall -t -r
> repro-app-001" --title "before restart" --runs 10
> {code}
> # Wait for the JFR recording to finish
> # Restart Karaf without cleaning the {{data}} folder, and wait until all
> bundles are in the state {{Active}}
> # (Optional) Check the {{feature:install}} and {{feature:uninstall}}
> performance manually as in step *8*
> # Repeat step *9* with:
> {code:bash}
> jcmd $(cat ./apache-karaf-4.4.11/karaf.pid) JFR.start duration=120s
> settings=profile jdk.ExecutionSample#period=10ms
> jdk.NativeMethodSample#period=10ms
> filename=default_karaf_after_jvm_restart.jfr && \
> python3 measure_feature_uninstall.py --client
> ./apache-karaf-4.4.11/bin/client --command "feature:uninstall -t -r
> repro-app-001" --title "after restart" --runs 10
> {code}
> # Wait for the recording to finish
> What to look for in the recordings
> - {*}default_karaf_before_jvm_restart.jfr:{*} shows
> {{ArrayList.hashCodeRange}} as the top Java method:
> !image-2026-10-01-20-31-40-225.png!
> - {*}default_karaf_after_jvm_restart.jfr:{*} {{{}ArrayList.hashCodeRange{}}}
> is gone from the Java samples (and from JMC's Method Profiling page). The
> features thread now spends most of its time inside a native method, which JFR
> records as a separate event, {{jdk.NativeMethodSample}} (JMC: Event Browser →
> Java Application → Method Profiling Sample Native). {{jfr view native-methods
> after_restart.jfr}} lists {{{}java.lang.Object.hashCode{}}}; the other
> entries there are idle I/O threads. In each of those samples,
> {{java.util.ArrayList.hashCodeRange}} is the frame right below
> {{java.lang.Object.hashCode;}}
> h3. *Proposal*
> One way to fix this is to cache the result of
> [ResourceImpl.hashCode|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L131]
> and only recompute it when the [List<Capability>
> caps|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L36]
> or\{{ }}[List<Requirement>
> reqs|https://github.com/apache/felix-dev/blob/b47fa6abb20ff10dbd86574e4df68cd959da5c26/utils/src/main/java/org/apache/felix/utils/resource/ResourceImpl.java#L37]
> change.
> The fix can be tested in either of the following ways, before step {{2}} from
> the "{*}Steps to reproduce{*}":
> * Replace
> {{./apache-karaf-4.4.11/system/org/apache/karaf/features/org.apache.karaf.features.core/4.4.11/org.apache.karaf.features.core-4.4.11.jar}}
> with the attached jar.
> * Build {{org.apache.felix:org.apache.felix.utils}} locally from the
> proposed PR, then rebuild
> [org.apache.karaf.features:org.apache.karaf.features.core|https://github.com/apache/karaf/blob/karaf-4.4.11/features/core/pom.xml]
> against it, and replace
> {{./apache-karaf-4.4.11/system/org/apache/karaf/features/org.apache.karaf.features.core/4.4.11/org.apache.karaf.features.core-4.4.11.jar}}
> |Kars installed|feature:uninstall before restart|after restart|after restart,
> with the fix|
> |1|1.3 s|2.3 s|1.4 s|
> |300|~4 s|~22 s|~3.5 s|
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
