Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

~150 millisecond hotspot under the picocli.CommandLine$Help$Ansi$Text.toString method #1975

Closed
ChrisTrenkamp opened this issue Mar 19, 2023 · 6 comments · Fixed by #1976
Closed
Labels
theme: usagehelp An issue or change related to the usage help message type: enhancement ✨ type: performance ⏱ Performance-related
Milestone

Comments

@ChrisTrenkamp
Copy link
Contributor

image

In my program's initialization, there's a bunch of Class.forName calls, half of them seem to come from picocli's CommandLine$Help$Ansi$Text.toString method. It appears to be looking for jansi classes. The above screenshot shows this is taking about 150 milliseconds to complete. I can confirm that passing in -Dpicocli.ansi=false to the Java commandline works around this issue. I'm running this on Windows.

https://github.com/remkop/picocli/blob/051a51d07ef917913aec53759ceeac0893591617/src/main/java/picocli/CommandLine.java#L17800-L17829

I don't have org.fusesource.jansi on my classpath. I wouldn't expect the total time for the isJansiConsoleInstalled method to take 150 milliseconds, unless it was repeatedly called in a loop, which I don't think it is. It should complete instantaneously.

Anyone know what's going on here?

@ChrisTrenkamp
Copy link
Contributor Author

ChrisTrenkamp commented Mar 19, 2023

My previous comment was wrong. isJansiConsoleInstalled is called repeatedly in a loop:

This Text#toString method is repeatedly called in a loop:
https://github.com/remkop/picocli/blob/051a51d07ef917913aec53759ceeac0893591617/src/main/java/picocli/CommandLine.java#L17358

And the first thing Text#toString does is check if Ansi is enabled, which repeatedly calls the isJansiConsoleInstalled method, causing the hotspot:
https://github.com/remkop/picocli/blob/051a51d07ef917913aec53759ceeac0893591617/src/main/java/picocli/CommandLine.java#L18214

@ChrisTrenkamp
Copy link
Contributor Author

ChrisTrenkamp commented Mar 19, 2023

What would the proper fix for this be?

Should the TextTable#toString method cache the Ansi#enabled result, and extract the Text#toString method into an overloaded method that accepts a boolean argument that determines if the output is Ansi?

Or should the Ansi#enabled method cache the result in a private member so it doesn't repeatedly call the isJansiConsoleInstalled method?

@remkop
Copy link
Owner

remkop commented Mar 19, 2023

Thank you for raising this and thank you for the investigation!
Super helpful!

For the solution, I'd go even lower level and cache the result of isJansiConsoleInstalled; because this cannot change at runtime.

I don't like caching the result of Ansi::enabled because it may depend on system properties which can be modified at runtime. But caching the expensive operation (that doesn't change) certainly makes sense!

@remkop remkop added this to the 4.7.2 milestone Mar 20, 2023
@remkop remkop added type: enhancement ✨ theme: usagehelp An issue or change related to the usage help message type: performance ⏱ Performance-related labels Mar 20, 2023
remkop added a commit that referenced this issue Mar 24, 2023
remkop added a commit that referenced this issue Apr 2, 2023
@maxandersen
Copy link
Contributor

do I get it right that if you have jansi on classpath this change does not change things - its only if you do not include jansi?

@remkop
Copy link
Owner

remkop commented Apr 19, 2023

@maxandersen I'm not sure to be honest.
If jansi is on the classpath, the Class.forName may return faster once the class is loaded, but I don't know for sure.
The caching will avoid the call to Class.forName so I suspect it is still faster but I have not measured any of this...

@maxandersen
Copy link
Contributor

10 runs of 'jbang' aversge startup does not seem to change with 4.7 vs 4.6.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
theme: usagehelp An issue or change related to the usage help message type: enhancement ✨ type: performance ⏱ Performance-related
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants