SpringConfigurationPropertySource.DelegatingPropertyMapper.callMappers() is showing up in Flight Recorder as a source of GC pressure (the main source when only executing LoggingApplicationListener in a tight loop). It gets called a lot, and creates a lot of temporary arrays.
SpringIterableConfigurationPropertySource.getPropertyMappings() was a close second on the GC pressure hot list.
Kind of a special case of #13565.
Comment From: dsyer
There's a lot of caching going on as well in SpringIterableConfigurationPropertySource and on balance I think that might save us from actually experiencing the GC pressure that the tight loop showed up above. One change that might be worth making would be to try and ensure that this cache gets re-used - e.g. by making sure that only one Binder is created per SpringApplication or per Environment. If I do that in the tight loop test above (i.e. re-use the same Binder) the GC pressure from PropertyMapping and ConfigurationPropertyName disappears and the overall performance improves by a factor of about 2.
Comment From: wilkinsona
The tight loop is a bit of a micro-benchmark. Can you quantify the contribution to GC pressure in a more real-world scenario please?
SpringConfigurationPropertySource.DelegatingPropertyMapper.callMappers() is showing up in Flight Recorder as a source of GC pressure
Is this from the tight loop or from a "proper" app? I'm asking so that we can prioritise this accordingly.
Comment From: dsyer
It's real, and the microbenchmark is really just to show how bad it is if you zoom in on it. So the answer to your specific question is that it's only visible as GC pressure in the microbenchmark, but you can see the processing time spent in Binder clearly in a "proper app". We spend a lot of time, relative to the benefit (IMO) doing metadata construction in Binder during startup. I don't have an accurate figure, and it's hard to measure (hence the microbenchmark), but it's probably as much as 10%.
However, if we are talking about priorities, I would say that it is better to see this as part of #13565. The comments above indicated as much. It wouldn't be so bad to do this work once (even if some of it is unnecessary), as long as it could be re-used. I think it is mostly to do with creating the canonical form of all System property and OS environment variable key names. The key names are mostly immutable, and even if the user is setting System properties at runtime, we could still cache more to reuse this metadata.
Comment From: SeifMostafa
Hello, Any help?
Comment From: philwebb
@SeifMostafa Please stop asking the same question on multiple issues.
Comment From: snicoll
@dsyer I know it's been a while but I am trying to asses if this issue is still actionable. Do you still have the benchmark around and, if so, can you please run it against Spring Boot 4?
Comment From: dsyer
I still have the benchmarks. It's going to take a bit of time to patch them up to Boot 4.
Comment From: dsyer
I got it working with Boot 3.5.7. There's still a massive tax on using Binder vs direct access to the Environment:
Benchmark Mode Cnt Score Error Units
BinderBenchmark.binder thrpt 5 9610.715 ± 238.799 ops/s
BinderBenchmark.direct thrpt 5 1485929.502 ± 18471.418 ops/s
BinderBenchmark.map thrpt 5 283601.305 ± 16690.901 ops/s
BinderBenchmark.wrapped thrpt 5 197042.321 ± 22997.803 ops/s
The "direct" sample uses Environment.getProperty(), and the "binder" sample uses Binder.bind(). The "map" benchmark uses a MapConfigurationPropertySource instead of the full Environment in the Binder (I noticed this pattern in XADataSourceAutoConfiguration).
Comment From: dsyer
Here are the same results for Boot 4 (pretty similar):
Benchmark Mode Cnt Score Error Units
BinderBenchmark.binder thrpt 5 9460.616 ± 182.386 ops/s
BinderBenchmark.direct thrpt 5 1411077.688 ± 28872.501 ops/s
BinderBenchmark.map thrpt 5 283695.559 ± 3263.429 ops/s
BinderBenchmark.wrapped thrpt 5 203861.159 ± 2966.348 ops/s
Source code here: https://github.com/dsyer/spring-boot-allocations/tree/boot4
Comment From: philwebb
I've added some additional caching, but I think the main thing that will help with the benchmark is calling ConfigurationPropertySources.attach to that the existing caches are reused.
If I updated EnvironmentState.init() with ConfigurationPropertySources.attach(environment); then I get the following figures with the new cache in place:
Previous
Benchmark Mode Cnt Score Error Units
BinderBenchmark.binder thrpt 5 24094.516 ± 93.075 ops/s
BinderBenchmark.direct thrpt 5 2106894.717 ± 128650.727 ops/s
BinderBenchmark.map thrpt 5 468784.046 ± 7327.413 ops/s
BinderBenchmark.wrapped thrpt 5 335434.093 ± 5232.333 ops/s
class, method, median, mean, range
com.example.bench.BinderBenchmark, binder, 24066.852, 24094.516, 28.440
com.example.bench.BinderBenchmark, direct, 2075528.238, 2106894.717, 38333.909
com.example.bench.BinderBenchmark, map, 465721.234, 468784.046, 2222.933
com.example.bench.BinderBenchmark, wrapped, 333941.010, 335434.093, 1580.316
With attache and new cache
Benchmark Mode Cnt Score Error Units
BinderBenchmark.binder thrpt 5 127955.358 ± 2955.192 ops/s
BinderBenchmark.direct thrpt 5 541210.498 ± 6813.770 ops/s
BinderBenchmark.map thrpt 5 452317.151 ± 7892.598 ops/s
BinderBenchmark.wrapped thrpt 5 122584.858 ± 3114.225 ops/s
class, method, median, mean, range
com.example.bench.BinderBenchmark, binder, 127380.207, 127955.358, 948.983
com.example.bench.BinderBenchmark, direct, 540186.475, 541210.498, 2083.934
com.example.bench.BinderBenchmark, map, 450702.280, 452317.151, 2570.579
com.example.bench.BinderBenchmark, wrapped, 121643.259, 122584.858, 959.518
@dsyer I'll close this issue for now, but if you've got more examples or benchmarks please feel free to open a new issue.