springdoc / springdoc-openapi

Library for OpenAPI 3 with spring-boot
https://springdoc.org
Apache License 2.0
3.25k stars 492 forks source link

Long init times for springdoc-openapi #1737

Closed mdoh closed 2 years ago

mdoh commented 2 years ago

Describe the bug I switched one of my projects from swagger to springdoc-openapi. We have a lot endpoints and the rendering of the swagger-ui takes very long Init duration for springdoc-openapi is: 52103 ms

I made a sample spring-boot project where you can see the behaviour with one endpoint only. I have the feeling that the model got read with every endpoint I add (hence the high amount of time for initialization). When I add just a simple class as return value the initialization is fast (<1 Sec).

To Reproduce spring-boot: 2.7.1. (also tried 2.6.6) springdoc-openapi 1.6.9 (also tried 1.6.8) The sample project can be found here: https://github.com/mdoh/test-api-server

It is a multi module Maven project, where I generate the Spring-Boot interfaces from the openapi.yml in the api and the implement these in the server part. I also tries to put the generated openapi.json in my server resources directory with the same result.

Expected behavior Render the swagger-ui as fast as before.

bnasslahsen commented 2 years ago

@mdoh,

You are not mentionning the characteristics of your system for this performance report. Anyway, here are some benches:

Initial startup: Init duration for springdoc-openapi is: 1099 ms. And this is only for the first client access, After that all is cached.

Note that most of the time is spent not in springdoc-openapi code, but the way swagger-core resolves the schemas. After that, it all depends in the complexity for each model. as you can see the average call is 1.3 micro-seconds.

image

We will not invest more efforts on springdoc-openapi side.

You can add springdoc.pre-loading-enabled=true, There will be improvement of at least 20% ...

mdoh commented 2 years ago

@bnasslahsen I run it on an M1 Max, Spring-Boot 2.7.1., Java 17.

The problem is, that if I uncomment the other endpoints in the controller the loading times are going up. One second per endpoint. I don't understand why this is, I think the model is generated with each endpoint again and again and this takes the time. So when I have 50 endpoint I have 50 seconds loading time! I just wanted to keep the example small. Sorry not being that clear the first time.

I added now 10 endpoints to the Controller, all are repsonding the same model.

Init duration for springdoc-openapi is: 10243 ms

I updated the example project.

It would be nice if you could have a look!

Thank you

thlaegler commented 1 year ago

We're facing the same issue where the initial load time of OpenApi is almost 1 minute(!)

[org.example.SpringApplication] Started SpringApplication in 6.783 seconds (JVM running for 7.317)
[org.springdoc.api.AbstractOpenApiResource] Init duration for springdoc-openapi is: 50662 ms

We just have 10 simple models each with endpoints for about 12 simple CRUD (and bulk CRUD) operations but based on the same domain model. Those models are relatively large (~60 fields) but they are "flat", means they don't have any nested sub-models. We're also currently exposing the Spring-boot actuator endpoints in OpenAPI. So total number of endpoints of about 150. E.g.

{GET [/api/v1/disruptions/required-fields]}: getMinimumRequiredFields()
{GET [/api/v1/disruptions]}: getAllDisruptions()
{GET [/api/v1/disruptions/{id}]}: getDisruptionById(Integer)
{GET [/api/v1/disruptions/disruption-id/{disruptionId}]}: getDisruptionByDisruptionId(String)
{GET [/api/v1/disruptions/status/{status}]}: getDisruptionsByStatus(String)
{GET [/api/v1/disruptions/report-id/{reportId}]}: getAllDisruptionsByReportId(Integer)
{POST [/api/v1/disruptions]}: createNewDisruption(Disruption)
{POST [/api/v1/disruptions/bulk]}: createNewDisruptionsInBulk(List)
{PUT [/api/v1/disruptions/{id}]}: updateDisruptionById(Integer,Disruption)
{PUT [/api/v1/disruptions/bulk]}: updateDisruptionsInBulk(List)
{DELETE [/api/v1/disruptions/{id}]}: deleteDisruptionById(Integer)
{DELETE [/api/v1/disruptions/all]}: deleteAllDisruptions()

Pre-loading is already enabled: springdoc.pre-loading-enabled: true

When I copy the OAS3 json specification (about 17000 lines) and paste in into https://editor.swagger.io it takes only about 2 seconds to render the Swagger-UI. So, it seems the issue is not swagger-core, but springdoc-openapi.

loadtime

DimitriSCOLE commented 1 year ago

Is there any reason why the ticket is closed, I have same issue a project with a lot of endpoints and it take 1minutes and a lot of resources

Avanishkumar28 commented 1 year ago

I'm having same issue with my project. I have 100+ endpoint server took approximately ~15 mins. Although I have set property springdoc.pre-loading-enabled: true but when I hit first request from browser, server again initialising o.springdoc.api.AbstractOpenApiResource So in my server logs I can see 2023-07-10T09:52:31.103Z INFO 22964 --- [pool-12-thread-1] o.springdoc.api.AbstractOpenApiResource : Init duration for springdoc-openapi is: 853743 ms

and again when I hit first request from browser-

2023-07-10T10:10:14.392Z INFO 22964 --- [io-13080-exec-1] o.springdoc.api.AbstractOpenApiResource : Init duration for springdoc-openapi is: 828973 ms

No Idea why it is re-initialising.

System details Windows 11, 16 GB RAM, Processor- AMD EPYC 7763 64-Core

Any help will appreciate!

JayAhn2 commented 1 year ago

Seems springdoc.pre-loading-enabled: true doesn't work as expected.

I can see Init duration for springdoc-openapi is: xxxx ms right after app is started, but when I access /v3/api-docs in my browser, it is re-initialized and show the Init Duration log again. (same issue as @Avanishkumar28 mentioned)

Looks like it doesn't cache when it is not triggered from a browser

2023-09-01 16:00:33.879  INFO 64234 --- [  restartedMain] co.sprintapp.api.ApplicationKt           : Started ApplicationKt in 22.48 seconds (JVM running for 22.811)
2023-09-01 16:00:37.434  INFO 64234 --- [ool-12-thread-1] o.springdoc.api.AbstractOpenApiResource  : Init duration for springdoc-openapi is: 4628 ms
2023-09-01 16:00:42.708  INFO 64234 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2023-09-01 16:00:42.708  INFO 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2023-09-01 16:00:42.709 DEBUG 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected StandardServletMultipartResolver
2023-09-01 16:00:42.709 DEBUG 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected AcceptHeaderLocaleResolver
2023-09-01 16:00:42.709 DEBUG 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected FixedThemeResolver
2023-09-01 16:00:42.725 DEBUG 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected org.springframework.web.servlet.view.DefaultRequestToViewNameTranslator@4fd77ee7
2023-09-01 16:00:42.726 DEBUG 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected org.springframework.web.servlet.support.SessionFlashMapManager@385c06ac
2023-09-01 16:00:42.727 DEBUG 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : enableLoggingRequestDetails='false': request parameters and headers will be masked to prevent unsafe logging of potentially sensitive data
2023-09-01 16:00:42.727  INFO 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 19 ms
2023-09-01 16:00:42.743 DEBUG 64234 --- [nio-8080-exec-1] c.s.a.common.loggers.ControllerProfiler  : [GET] /v3/api-docs: Request Started
2023-09-01 16:00:42.744 DEBUG 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : GET "/v3/api-docs", parameters={}
2023-09-01 16:00:46.566  INFO 64234 --- [nio-8080-exec-1] o.springdoc.api.AbstractOpenApiResource  : Init duration for springdoc-openapi is: 3780 ms
2023-09-01 16:00:46.660 DEBUG 64234 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2023-09-01 16:00:46.662  WARN 64234 --- [nio-8080-exec-1] c.s.a.common.loggers.ControllerProfiler  : 3918 ms (over 1000 ms!) | [GET] /v3/api-docs
JayAhn2 commented 1 year ago

I just found that it is related difference of locale between server and browser. When I checked the log, default locale in server was en_KR, but when I open swagger ui from browser, it was en_US.

I set my server's default locale to en_US, and now the browser can use pre-loaded cache.