Spring Security Long Application Startup Time

Summary

We are experiencing very long application startup times. When I enable trace logging for package org.springframework, I see repeated logs as follows:

2018-11-07 20:07:27,257 TRACE [localhost-startStop-1 ''] org.springframework.security.access.prepost.PrePostAnnotationSecurityMetadataSource - Looking for Pre/Post annotations for method 'configureMessageConverters' on target class 'class springfox.documentation.spring.web.ObjectMapperConfigurer' 2018-11-07 20:07:27,257 TRACE [localhost-startStop-1 ''] org.springframework.security.access.prepost.PrePostAnnotationSecurityMetadataSource - Looking for Pre/Post annotations for method 'jackson2Converters' on target class 'class springfox.documentation.spring.web.ObjectMapperConfigurer'

And this repeats for every class of every jar in our application. I wasn't able to find a way to limit this scanning.

Actual Behavior

The scanning occurs across all classes in all jars

Expected Behavior

We would like to limit the scanning to just our application packages to optimize the startup time

Configuration

WAR package built with Maven

Version

spring 5.0.7.RELEASE spring security 5.0.6.RELEASE

Comment From: edavedian

An excerpt of the XML configuration is as follows:

    <security:global-method-security
        secured-annotations="enabled" pre-post-annotations="enabled" order="200">
        <security:expression-handler ref="expressionHandler" />
    </security:global-method-security>

Comment From: rwinch

@edavedian Thanks for the report. Can you provide what the startup time is when method security is enabled and when it is not?

Comment From: edavedian

@rwinch Thank you very much. The startup time without method security wasn't reduced due to a lot of other repeated scanning:

2018-11-07 22:57:38,964 DEBUG [localhost-startStop-1 ''] org.springframework.core.io.support.PathMatchingResourcePatternResolver - Resolved classpath location [org/springframework/amqp/] to resources [URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-amqp-2.0.4.RELEASE.jar!/org/springframework/amqp/]]
2018-11-07 22:57:38,965 DEBUG [localhost-startStop-1 ''] org.springframework.core.io.support.PathMatchingResourcePatternResolver - Looking for matching resources in jar file [file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar]
2018-11-07 22:57:38,967 DEBUG [localhost-startStop-1 ''] org.springframework.core.io.support.PathMatchingResourcePatternResolver - Looking for matching resources in jar file [file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar]
2018-11-07 22:57:38,985 DEBUG [localhost-startStop-1 ''] org.springframework.core.io.2018-11-07 22:57:38,990 DEBUG [localhost-startStop-1 ''] org.springframework.core.io.support.PathMatchingResourcePatternResolver - Resolved location pattern [classpath*:org/springframework/amqp/*/**/*.class] to resources [URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender$Event.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender$EventSender.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender$EventSender$1.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/ListenerContainerFactoryBean$Type.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/AnnotationDrivenParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/ConnectionFactoryParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/RabbitListenerConfigUtils.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/StatefulRetryOperationsInterceptorFactoryBean.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/RetryInterceptorBuilder.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/QueueParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/FanoutExchangeParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/AbstractRetryOperationsInterceptorFactoryBean.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/AdminParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/DirectExchangeParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/RabbitNamespaceHandler.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/SimpleRabbitListenerEndpoint.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/AbstractExchangeParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/TemplateParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/RetryInterceptorBuilder$StatefulRetryInterceptorBuilder.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/HeadersExchangeParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/TopicExchangeParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/RabbitNamespaceUtils.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/ListenerContainerFactoryBean.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/AbstractRabbitListenerContainerFactory.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/DirectRabbitListenerContainerFactory.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/BindingFactoryBean.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/SimpleRabbitListenerContainerFactory.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/ListenerContainerParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/StatelessRetryOperationsInterceptorFactoryBean.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/NamespaceUtils.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/RetryInterceptorBuilder$StatelessRetryInterceptorBuilder.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/config/QueueArgumentsParser.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/AsyncRabbitTemplate$AsyncCorrelationData.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/MessageListenerContainer.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/RabbitListenerEndpointRegistry.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/MethodRabbitListenerEndpoint.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/DirectReplyToMessageListenerContainer.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/RabbitListenerErrorHandler.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/ConditionalRejectingErrorHandler.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/ActiveObjectCounter.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/BlockingQueueConsumer.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/AbstractMessageListenerContainer$ContainerDelegate.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/MessagingMessageListenerAdapter.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/MessageListenerAdapter.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/ReplyingMessageListener.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/MessagingMessageListenerAdapter$MessagingMessageConverterAdapter.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/DelegatingInvocableHandler.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/ReplyFailureException.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/AbstractAdaptableMessageListener.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/HandlerAdapter.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/AbstractAdaptableMessageListener$ResultHolder.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/adapter/AbstractAdaptableMessageListener$ReplyExpressionRoot.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/AsyncConsumerStartedEvent.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/springframework/amqp/rabbit/listener/ListenerContainerConsumerTerminatedEvent.class], URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/spring-rabbit-2.0.4.RELEASE.jar!/org/sp
2018-11-07 22:57:38,991 TRACE [localhost-startStop-1 ''] org.springframework.context.annotation.ClassPathBeanDefinitionScanner - Scanning URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender$Event.class]
2018-11-07 22:57:39,009 TRACE [localhost-startStop-1 ''] org.springframework.context.annotation.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender$Event.class]
2018-11-07 22:57:39,009 TRACE [localhost-startStop-1 ''] org.springframework.context.annotation.ClassPathBeanDefinitionScanner - Scanning URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender$EventSender.class]
2018-11-07 22:57:39,013 TRACE [localhost-startStop-1 ''] org.springframework.context.annotation.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender$EventSender.class]
2018-11-07 22:57:39,013 TRACE [localhost-startStop-1 ''] org.springframework.context.annotation.ClassPathBeanDefinitionScanner - Scanning URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender$EventSender$1.class]
2018-11-07 22:57:39,013 TRACE [localhost-startStop-1 ''] org.springframework.context.annotation.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender$EventSender$1.class]
2018-11-07 22:57:39,013 TRACE [localhost-startStop-1 ''] org.springframework.context.annotation.ClassPathBeanDefinitionScanner - Scanning URL [jar:file:/apps/colp/apache-tomcat-8.5.12/webapps/ROOT/WEB-INF/lib/external_services-mb-2018.4.1.5.jar!/org/springframework/amqp/rabbit/log4j/AmqpAppender.class]

Comment From: rwinch

What was the startup time before and after? If it isn't significant, I don't think this is really a feature we want to worry about.

Comment From: edavedian

It is about 6 minutes.

Comment From: rwinch

Thanks, but that doesn't answer my question. What is the amount of time it takes to startup the application with Spring Security's method security enabled? Also what is the amount of time it takes to startup the application without Spring Security's method security enabled?

Comment From: edavedian

@rwinch Very sorry for the delay. The startup time with and without Spring Security's method security enabled was 6 minutes. I will need to look into other scanning issues which is causing the startup delay startup. But if I want to limit Spring Security's scanning, can I remove

pre-post-annotations="enabled"

and instead use

protect-pointcut 

Comment From: rwinch

Yes that would work. I think the key is to ensure that the issue is Spring Security and not something else. I'd recommend starting it with a profiler and finding out where it slow.

Given that the app starts the same with and without Spring Security, I'm going to close this. I don't think there is a problem with Spring Security.