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

Add the ability to print the startup time of each build step #10294

Merged
merged 1 commit into from Jul 6, 2020

Conversation

geoand
Copy link
Contributor

@geoand geoand commented Jun 26, 2020

This has been discussed a couple times and I myself could have
used it when I was looking into the Flyway startup times

@geoand
Copy link
Contributor Author

geoand commented Jun 26, 2020

@stuartwdouglas @gsmet I would like your opinion on this. Currently to enable this a user needs to set the system property both when building and when running the application, which means that under normal circumstances we don't pollute the bytecode with extra instructions, but I am pretty sure that this experience will puzzle users :).

For native, obviously only the main startup tasks will print there startup time (unless a user really knows what they are doing and goes to extreme of passing the system property with -J-D... to the native image generation as well..)

Also if we want this, it probably needs to be documented somewhere - the extension authors guide and / or the performance troubleshooting doc?

@stuartwdouglas
Copy link
Member

I think that experience will be be a bit confusing.

I was thinking this could live in MainClassBuildStep, and just be abstracted into a function, so the only 'pollution' is a method call before each step (which is a noop if the property is not set). It should add basically 0 overhead. You can then store the enabled state and last step finish time in a static variable, so it should be very minimal.

@geoand
Copy link
Contributor Author

geoand commented Jul 2, 2020

@stuartwdouglas so IIUC you want to see the control of printing of the startup times be a build time property? So if a user builds the application with that property then the startup times will always be printed when the application is run?

I am thinking of another idea: Keep my initial approach, but when the application is built with the print startup times enabled, then by default it does print startup times, but you can opt-out of that behavior by setting the flag to false at runtime. How does that sound?

I pushed an update that does just that

@stuartwdouglas
Copy link
Member

No, I meant that we always include the profiling code, but just do it in a way that adds basically no overhead.

@geoand
Copy link
Contributor Author

geoand commented Jul 3, 2020

PR updated. If you agree with the current approach, then I'll go ahead and squash the commits and take it out of draft

@geoand geoand added this to the 1.7.0 - master milestone Jul 3, 2020
@geoand geoand force-pushed the build-step-startup-times branch 2 times, most recently from 69398b5 to 4015a51 Compare July 6, 2020 05:11
@geoand
Copy link
Contributor Author

geoand commented Jul 6, 2020

Commits squashed

@geoand geoand marked this pull request as ready for review July 6, 2020 06:13
@geoand
Copy link
Contributor Author

geoand commented Jul 6, 2020

I'll also add a small piece of documentation later on Done

@gsmet gsmet force-pushed the build-step-startup-times branch from fa70fb6 to 86b9fda Compare July 6, 2020 12:30
@gsmet gsmet merged commit 30baf78 into quarkusio:master Jul 6, 2020
@geoand geoand deleted the build-step-startup-times branch July 6, 2020 13:35
@mkouba
Copy link
Contributor

mkouba commented Jul 6, 2020

@geoand Hm, what's the difference compared to the debug output from the io.quarkus.builder? E.g. if you run your build with -X then you can see messages like:

[DEBUG] [io.quarkus.builder] Finished step "io.quarkus.arc.deployment.LifecycleEventsBuildStep#startupEvent" in 5 ms

@geoand
Copy link
Contributor Author

geoand commented Jul 6, 2020

@mkouba that is for build time build steps.

This PR introduces the ability to see the the time each generated startup task when you run the application

@mkouba
Copy link
Contributor

mkouba commented Jul 6, 2020

Ah, I see. That makes sense.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants