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

Automatic Extensionless Mapping - Startup Performance Issues #5510

Open
RohdeSchwarz-SDC opened this issue Oct 8, 2024 · 8 comments
Open

Comments

@RohdeSchwarz-SDC
Copy link

Problem

As soon as I enable the feature jakarta.faces.AUTOMATIC_EXTENSIONLESS_MAPPING the webserver starts really slowly!
Maybe there is something you (or we) could do?

Setup

  • Tomcat 10.1
  • OpenWebBeans 2.0.27
  • Jakarta Faces 4.0.8 (Mojarra)
  • PrimeFaces 14.0.5

Logs

AUTOMATIC_EXTENSIONLESS_MAPPING = false

08-Oct-2024 16:19:37.224 INFORMATION [main] org.apache.tomcat.util.net.AbstractEndpoint.logCertificate Connector [https-openssl-nio-8443], TLS virtual host [_default_], certificate type [RSA] configured from keystore [conf/certificate.p12] using alias [tomcat] with trust store [null]
08-Oct-2024 16:19:37.230 INFORMATION [main] org.apache.catalina.startup.Catalina.load Server initialization in [976] milliseconds
08-Oct-2024 16:19:37.287 INFORMATION [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
08-Oct-2024 16:19:37.288 INFORMATION [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/10.1.24]
08-Oct-2024 16:19:39.670 INFORMATION [main] org.apache.webbeans.lifecycle.AbstractLifeCycle.bootstrapApplication OpenWebBeans Container is starting...
08-Oct-2024 16:19:39.699 INFORMATION [main] org.apache.webbeans.corespi.scanner.AbstractMetaDataDiscovery.addWebBeansXmlLocation added beans archive URL: file:/W:/tools/web/apache-tomcat/v10/lib/
08-Oct-2024 16:19:39.700 INFORMATION [main] org.apache.webbeans.corespi.scanner.AbstractMetaDataDiscovery.addWebBeansXmlLocation added beans archive URL: file:/W:/eclipse/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/myWebApp/WEB-INF/classes/
08-Oct-2024 16:19:41.639 INFORMATION [main] org.apache.webbeans.config.BeansDeployer.validateInjectionPoints All injection points were validated successfully.
08-Oct-2024 16:19:41.642 INFORMATION [main] org.apache.webbeans.lifecycle.AbstractLifeCycle.bootstrapApplication OpenWebBeans Container has started, it took [1969] ms.
08-Oct-2024 16:19:41.691 INFORMATION [main] com.sun.faces.config.ConfigureListener.contextInitialized Mojarra 4.0.8 für Kontext '/myWebApp' wird initialisiert.
08-Oct-2024 16:19:42.478 INFORMATION [main] com.sun.faces.spi.InjectionProviderFactory.createInstance JSF1048: PostConstruct/PreDestroy-Annotationen vorhanden.  Verwaltete Bean-Methoden, die mit diesen Annotationen markiert sind, lassen die entsprechenden Annotationen verarbeiten.
08-Oct-2024 16:19:44.450 INFORMATION [main] org.primefaces.webapp.PostConstructApplicationEventListener.processEvent Running on PrimeFaces 14.0.5
08-Oct-2024 16:19:44.451 INFORMATION [main] org.primefaces.extensions.application.PostConstructApplicationEventListener.processEvent Running on PrimeFaces Extensions 14.0.5
08-Oct-2024 16:19:47.315 INFORMATION [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
08-Oct-2024 16:19:47.365 INFORMATION [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["https-openssl-nio-8443"]
08-Oct-2024 16:19:47.377 INFORMATION [main] org.apache.catalina.startup.Catalina.start Server startup in [10145] milliseconds

AUTOMATIC_EXTENSIONLESS_MAPPING = true

08-Oct-2024 16:20:52.731 INFORMATION [main] org.apache.catalina.startup.Catalina.load Server initialization in [1001] milliseconds
08-Oct-2024 16:20:52.773 INFORMATION [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
08-Oct-2024 16:20:52.773 INFORMATION [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/10.1.24]
08-Oct-2024 16:20:55.103 INFORMATION [main] org.apache.webbeans.lifecycle.AbstractLifeCycle.bootstrapApplication OpenWebBeans Container is starting...
08-Oct-2024 16:20:55.146 INFORMATION [main] org.apache.webbeans.corespi.scanner.AbstractMetaDataDiscovery.addWebBeansXmlLocation added beans archive URL: file:/W:/tools/web/apache-tomcat/v10/lib/
08-Oct-2024 16:20:55.149 INFORMATION [main] org.apache.webbeans.corespi.scanner.AbstractMetaDataDiscovery.addWebBeansXmlLocation added beans archive URL: file:/W:/eclipse/.metadata/.plugins/org.eclipse.wst.server.core/tmp1/wtpwebapps/myWebApp/WEB-INF/classes/
08-Oct-2024 16:20:57.299 INFORMATION [main] org.apache.webbeans.config.BeansDeployer.validateInjectionPoints All injection points were validated successfully.
08-Oct-2024 16:20:57.302 INFORMATION [main] org.apache.webbeans.lifecycle.AbstractLifeCycle.bootstrapApplication OpenWebBeans Container has started, it took [2197] ms.
08-Oct-2024 16:20:57.356 INFORMATION [main] com.sun.faces.config.ConfigureListener.contextInitialized Mojarra 4.0.8 für Kontext '/myWebApp' wird initialisiert.
08-Oct-2024 16:20:58.137 INFORMATION [main] com.sun.faces.spi.InjectionProviderFactory.createInstance JSF1048: PostConstruct/PreDestroy-Annotationen vorhanden.  Verwaltete Bean-Methoden, die mit diesen Annotationen markiert sind, lassen die entsprechenden Annotationen verarbeiten.
08-Oct-2024 16:21:05.289 INFORMATION [main] org.primefaces.webapp.PostConstructApplicationEventListener.processEvent Running on PrimeFaces 14.0.5
08-Oct-2024 16:21:05.303 INFORMATION [main] org.primefaces.extensions.application.PostConstructApplicationEventListener.processEvent Running on PrimeFaces Extensions 14.0.5
08-Oct-2024 16:21:08.176 INFORMATION [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
08-Oct-2024 16:21:08.223 INFORMATION [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["https-openssl-nio-8443"]
08-Oct-2024 16:21:08.236 INFORMATION [main] org.apache.catalina.startup.Catalina.start Server startup in [15506] milliseconds
@pizzi80
Copy link
Contributor

pizzi80 commented Oct 19, 2024

I'm not an OpenWebBeans user but as far as I can see
on their github repository you should use OpenWebBeans 4.0.2

How big is your webapp?

@BalusC
Copy link
Contributor

BalusC commented Oct 19, 2024

How big is your webapp?

It's a good question. How many XHTML files are there? Biggest bottleneck is in the ServletRegistration#addMapping() and the performance is servletcontainer impl dependent.

OWB has got nothing to do with this. Under the covers ServletContext#getResourcePaths() and ServletRegistration#addMapping() are being used which are part of the Servlet API.

@RohdeSchwarz-SDC
Copy link
Author

How big is your webapp?

It contains ~ 100 *.xhtml files, but only ~5 are "toplevel" files, the rest are <ui:composition> to be included via <ui:include>.
I tried to rename those ~95 to *.xhtml.composition but it did not improve the procession performance of PostConstruct/PreDestroy annotations.

My impression is that com.sun.faces.spi.InjectionProviderFactory.createInstance scans the webapp's classpath twice for bean annotations like @Named?

@RohdeSchwarz-SDC
Copy link
Author

Tried the same setup with alternative Jakarta Faces Implementation -> MyFaces

Same result 🤔

Can anybody reproduce this behaviour?

@BalusC
Copy link
Contributor

BalusC commented Dec 7, 2024

As said,

Biggest bottleneck is in the ServletRegistration#addMapping() and the performance is servletcontainer impl dependent.

Rather try a different servlet impl instead of a different faces impl.

Can anybody reproduce this behaviour?

Haven't tried yet.

@pizzi80
Copy link
Contributor

pizzi80 commented Dec 7, 2024

I would try with Java 21.0.5 and Tomcat 10.1.33 to see if it improves

@RohdeSchwarz-SDC
Copy link
Author

I would try with Java 21.0.5 and Tomcat 10.1.33 to see if it improves

Already running on Tomcat 10.1.33 and Java 23

@pizzi80
Copy link
Contributor

pizzi80 commented Dec 10, 2024

I've tested on a "Playground" webapp with ~150 copy pasted xhtml files
and there is no visible overhead with extensionless mapping true or false

  • Java Oracle 21.0.5
  • Tomcat 10.1.34
  • Weld 5.1.3.Final
  • Eclispe Jersey 3.1.9
  • OmniFaces 4.6
  • Jakarta Faces 4.0.8 (Mojarra)

The average startup time on a Core i5 12th gen is 2,400 milliseconds (2,4 seconds)

the tomcat startup process use all the cpu cores...
from the first post I see that your startup time is over 10 seconds even with extensionless off
which is a lot of time for a frontend only webapp,
which cpu are you using?

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

No branches or pull requests

3 participants