picocli
picocli copied to clipboard
remkop
startup time issues
I'm having an issue where my Spring Boot app is taking 2-9 seconds to start just to error out. That's way too long for a CLI app, profiling with JProfiler show's about 10% of the time is spent in picocli.
https://github.com/spring-projects/spring-boot/issues/26709 The Jar is currently taking 3 seconds (9 if I leave out tiered (only on fedora? not on windows... weird, wtf fedora)) to run on my system. Just to error out due to missing options and do nothing.
https://github.com/xenoterracide/brix/tree/7aa50ffcbac4defedae581d4ab5ba2b812feeaae
time java -Xverify:none -XX:TieredStopAtLevel=1 -jar modules/app/build/libs/app-0.1.0.jar # brix -> ccushing/copy-5-1
Missing required parameters: '<language>', '<moduleType>', '<project>'
Usage: <main class> [--repo=<repo>] [--workdir=<workdir>] <language>
<moduleType> <project> [COMMAND]
<language> The programming language you're generating code
for. Directory under --dir
<moduleType> The type of code you're generating e.g controller,
also the name of the config file without the
extension.
<project> The name of the project you're generating code for.
The name of the module to be created within the
project.
--repo=<repo> Repository path from the current working directory.
Templates and configs are looked up relative to
here. If the config isn't found here, then we
will search ~/.config/brix
--workdir=<workdir> The working directory you want your destination
paths to be relative to. Defaults to current
working directory
Default:
Commands:
run
java -Xverify:none -XX:TieredStopAtLevel=1 -jar 3.15s user 0.26s system 142% cpu 2.386 total
since it's a CLI app lazy init isn't helpful. This is worded like a question (that really would not be suitable for stackoverflow, I hate that SO is the support forum for things now, it's terrible because of the attitude of people that the objective is not to help people, also it's bad at getting answers for harder problems, spring should get a discourse or something again), but I also know I had a tika CLI app in the past that loaded in less than 1s without Tiered, so I'm also concerned it's a spring boot bug. I'm going to connect a profiler later to see what I can find, but I'm not sure that will do it.
Fedora 33
5.11.16-200.fc33.x86_64
14:08:34 up 3 days, 2:04, 1 user, load average: 0.79, 1.10, 1.66
total used free shared buff/cache available
Mem: 15G 11G 1.0G 1.4G 3.0G 2.3G
Swap: 12G 1.5G 10G
./gradlew :app:dependencyInsight --configuration runtimeClasspath --dependency spring-boot-starter-parent # brix -> ccushing/copy-5-1
Type-safe dependency accessors is an incubating feature.
Type-safe project accessors is an incubating feature.
> Task :app:dependencyInsight
org.springframework.boot:spring-boot-starter-parent:2.5.0
variant "platform-runtime" [
org.gradle.status = release (not requested)
org.gradle.usage = java-runtime
org.gradle.category = platform (compatible with: library)
Requested attributes not found in the selected variant:
org.gradle.libraryelements = jar
org.gradle.dependency.bundling = external
org.gradle.jvm.environment = standard-jvm
org.gradle.jvm.version = 11
]
Selection reasons:
- By constraint : dependency was locked to version '2.5.0'
- By ancestor
org.springframework.boot:spring-boot-starter-parent:{strictly 2.5.0} -> 2.5.0
\--- runtimeClasspath
org.springframework.boot:spring-boot-starter-parent:2.+ -> 2.5.0
+--- runtimeClasspath
+--- project :cli:api
| +--- project :cli:config
| | \--- runtimeClasspath
| +--- project :config-loader:yaml
| | \--- runtimeClasspath
| +--- project :processor:pebble
| | \--- runtimeClasspath
| +--- project :dispatch
| | \--- project :cli:config (*)
| +--- project :config-loader:service
| | \--- project :dispatch (*)
| \--- project :config-loader:api
| +--- project :config-loader:yaml (*)
| +--- project :processor:pebble (*)
| +--- project :processor:api
| | +--- project :processor:pebble (*)
| | \--- project :dispatch (*)
| \--- project :config-loader:service (*)
+--- project :cli:config (*)
+--- project :config-loader:api (*)
+--- project :config-loader:service (*)
+--- project :config-loader:yaml (*)
+--- project :dispatch (*)
+--- project :processor:api (*)
+--- project :processor:pebble (*)
+--- project :util:file
| +--- project :processor:pebble (*)
| \--- project :config-loader:service (*)
\--- project :util:lang
+--- project :processor:pebble (*)
\--- project :config-loader:service (*)
(*) - dependencies omitted (listed previously)
A web-based, searchable dependency report is available by adding the --scan option.
BUILD SUCCESSFUL in 1s
1 actionable task: 1 executed
./gradlew --version # brix -> ccushing/copy-5-1
------------------------------------------------------------
Gradle 7.0.2
------------------------------------------------------------
Build time: 2021-05-14 12:02:31 UTC
Revision: 1ef1b260d39daacbf9357f9d8594a8a743e2152e
Kotlin: 1.4.31
Groovy: 3.0.7
Ant: Apache Ant(TM) version 1.10.9 compiled on September 27 2020
JVM: 11.0.10 (AdoptOpenJDK 11.0.10+9)
OS: Linux 5.11.16-200.fc33.x86_64 amd64
I agree that 2-9 seconds is a long time to start up.
Looking at the profiler screenshots, I see ~150ms for picocli initialization, and 186ms for the command execution. The command execution is mostly displaying the usage help message, but 50ms of that is coming from Class.forName for the org.fusesource.jansi.AnsiConsole class. I have seen Class.forName taking a long time in applications that have a very large classpath. Not sure if it is possible for you to reduce that. One idea is to load that class explicitly in your application to ensure that it is cached.
Another thing to consider (not sure how feasible that is for you or how open you are to this) is to try a different framework than Spring Boot. Micronaut and Quarkus are engineered for very small startup, it may be an idea to look at these...?
Well, I'm considering looking at a different language, rust. Might be better to not use java. Yes things are adding up, death of a thousand cuts. And you can also see that I reported this to spring boot. I also noted that some of my stuff was high on the list so I figured out how to get it lazy loaded. But I only shaved off about a half a second.
I think there are ways around the class.forname you might ask the spring guys because I think they use something else, but realistically I'm not sure. I'm not even sure I use jansi that an optional dependency? I personally mostly use Linux and I certainly didn't need it there.
In theory jigsaw should help with that scanning but I'm not sure if it actually does, especially with automatic module names. And I had to stop on mine because of Tika I need to go yell at them too. Time for people to start including module-info as I believe that will stop the scanning of the whole jar. Again I could be wrong.
There was other stuff might be good to profile it yourself. Hence why I linked the whole repo.
https://github.com/spring-projects/spring-boot/issues/26709#issuecomment-851953515 also confirms this problem by the boot developer
I'm not even sure I use jansi that an optional dependency? I personally mostly use Linux and I certainly didn't need it there.
On what OS did you profile with flight recorder?
FYI, the 50ms coming from Class.forName for the org.fusesource.jansi.AnsiConsole class should only happen on Windows. On linux picocli would not try to load that class. So I would expect anything related to picocli's Ansi class to be quite a bit faster if profiled on Linux.
As you can see in The ticket it was fedora, So definitely Linux. That commit and repo is still there if you want to take a look. I think I tried on Manjaro too without any difference. It was so slow to load compounded by a few things. That I decided to allow my minion to redevelop it in rust.