[
https://issues.apache.org/jira/browse/FELIX-6863?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Stefan Tataru updated FELIX-6863:
---------------------------------
Attachment: default_karaf_after_jvm_restart.jfr
> 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.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, image-2026-10-02-13-11-49-447.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 in step *9*:
> {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 JFR recording to finish
> What to look for in the recordings
> - {*}default_karaf_before_jvm_restart.jfr:{*} shows
> {{ArrayList.hashCodeRange}} as the top Java method on the *Method Profiling*
> page in JDK Mission Control (JMC):
> !image-2026-10-01-20-31-40-225.png!
> - {*}default_karaf_after_jvm_restart.jfr:{*} {{ArrayList.hashCodeRange}} is
> gone from JMC's *Method Profiling* page, but the hot path is the same. The
> *Method Profiling* page only shows {{jdk.ExecutionSample}} events. After the
> restart, the hot method is native, so JFR captures it through
> {{jdk.NativeMethodSample}} events instead. To see these samples in JMC:
> *Event Browser* → *Java Virtual Machine* → *Profiling* → *Method Profiling
> Sample Native*. Sort by *Thread* and select all {{features-3-thread-1}} rows:
> !image-2026-10-02-13-11-49-447.png!
> 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, after step *1* in 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|https://github.com/apache/felix-dev/pull/564], 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}}
> with the built jar
> |Kars installed|feature:uninstall before restart|after restart|after restart,
> with the fix|
> |1|~1.3s|~2.3s|~1.4s|
> |300|~4s|~22s|~3.5s|
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
