Errors flood the logs when a duplicate site is in progress

[avasquez614]

Duplicates

• [X] I have searched the existing issues

Latest version

• [X] The issue is in the develop branch
• [X] The issue is in the latest released 4.1.x
• [ ] The issue is in the latest released 4.0.x
• [ ] The issue is in the latest released 3.1.x

Describe the issue

When a duplicate site is in progress, and you go to the Projects dashboard, this causes the Studio logs to start showing up a lot of errors that make it impossible to track the duplicate progess in the logs

Steps to reproduce

Steps:

1. Create a large site, that will make the duplicate process take some time
2. Duplicate the site
3. Close create dialog
4. Go to the Projects dashboard
5. Tail the Studio log

You should see a non-stop flurry of stack traces like the one attached. The errors don't seem to be useful, since they seem to happen because the UI is checking the site state with the backend, but it makes impossible to track anything else going on in the logs.

Relevant log output

[ERROR] 2024-04-25T13:52:09,436 [http-nio-8080-exec-9] [v2.ExceptionHandlers] | API endpoint 'https://mystudio.com/studio/api/2/configuration/get_configuration?environment=prod&module=studio&path=%2Fui.xml&siteId=mysite' failed with response 'ApiResponse{code=5002, message='Invalid site state', remedialAction='Requested site is not in the required state for this operation', documentationUrl=''}' 
org.craftercms.studio.api.v2.exception.InvalidSiteStateException: Site 'mysite' state ('LOCKED') is not the required value: 'READY'
    at org.craftercms.studio.impl.v2.service.site.internal.SitesServiceInternalImpl.checkSiteState(SitesServiceInternalImpl.java:233) ~[classes/:4.1.4E-BETA]
    at org.craftercms.studio.impl.v2.service.site.SitesServiceImpl.checkSiteState(SitesServiceImpl.java:121) ~[classes/:4.1.4E-BETA]
    at org.craftercms.studio.impl.v2.service.site.SitesServiceImpl$$FastClassBySpringCGLIB$$cbc67283.invoke(<generated>) ~[classes/:4.1.4E-BETA]
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:792) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:707) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.craftercms.studio.impl.v2.service.site.SitesServiceImpl$$EnhancerBySpringCGLIB$$2ce5a92e.checkSiteState(<generated>) ~[classes/:4.1.4E-BETA]
    at org.craftercms.studio.api.v2.annotation.RequireSiteStateAnnotationHandler.checkSiteState(RequireSiteStateAnnotationHandler.java:70) ~[classes/:4.1.4E-BETA]
    at jdk.internal.reflect.GeneratedMethodAccessor329.invoke(Unknown Source) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.craftercms.commons.security.permissions.annotations.HasPermissionAnnotationHandler.checkPermissions(HasPermissionAnnotationHandler.java:84) ~[crafter-commons-security-4.1.4E-BETA.jar:4.1.4E-BETA]
    at jdk.internal.reflect.GeneratedMethodAccessor325.invoke(Unknown Source) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:707) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.craftercms.studio.impl.v2.service.configuration.ConfigurationServiceImpl$$EnhancerBySpringCGLIB$$7cf29aa4.getConfigurationAsString(<generated>) ~[classes/:4.1.4E-BETA]
    at org.craftercms.studio.controller.rest.v2.ConfigurationController.getConfiguration(ConfigurationController.java:98) ~[classes/:4.1.4E-BETA]
    at org.craftercms.studio.controller.rest.v2.ConfigurationController$$FastClassBySpringCGLIB$$4e5d0378.invoke(<generated>) ~[classes/:4.1.4E-BETA]
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:792) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.validation.beanvalidation.MethodValidationInterceptor.invoke(MethodValidationInterceptor.java:123) ~[spring-context-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:762) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:707) ~[spring-aop-5.3.34.jar:5.3.34]
    at org.craftercms.studio.controller.rest.v2.ConfigurationController$$EnhancerBySpringCGLIB$$6b78392b.getConfiguration(<generated>) ~[classes/:4.1.4E-BETA]
    at jdk.internal.reflect.GeneratedMethodAccessor480.invoke(Unknown Source) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) ~[spring-web-5.3.34.jar:5.3.34]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150) ~[spring-web-5.3.34.jar:5.3.34]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117) ~[spring-webmvc-5.3.34.jar:5.3.34]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:903) ~[spring-webmvc-5.3.34.jar:5.3.34]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:809) ~[spring-webmvc-5.3.34.jar:5.3.34]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.3.34.jar:5.3.34]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1072) [spring-webmvc-5.3.34.jar:5.3.34]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:965) [spring-webmvc-5.3.34.jar:5.3.34]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) [spring-webmvc-5.3.34.jar:5.3.34]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) [spring-webmvc-5.3.34.jar:5.3.34]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:529) [servlet-api.jar:4.0.FR]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) [spring-webmvc-5.3.34.jar:5.3.34]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:623) [servlet-api.jar:4.0.FR]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:209) [catalina.jar:9.0.85]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [catalina.jar:9.0.85]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51) [tomcat-websocket.jar:9.0.85]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [catalina.jar:9.0.85]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [catalina.jar:9.0.85]
    at org.springframework.web.filter.ShallowEtagHeaderFilter.doFilterInternal(ShallowEtagHeaderFilter.java:106) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:354) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267) [spring-web-5.3.34.jar:5.3.34]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [catalina.jar:9.0.85]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [catalina.jar:9.0.85]
    at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176) [urlrewritefilter-4.0.4.jar:4.0.4]
    at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) [urlrewritefilter-4.0.4.jar:4.0.4]
    at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) [urlrewritefilter-4.0.4.jar:4.0.4]
    at org.craftercms.engine.url.rewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:65) [classes/:4.1.4E-BETA]
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:354) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267) [spring-web-5.3.34.jar:5.3.34]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [catalina.jar:9.0.85]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [catalina.jar:9.0.85]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:352) [spring-security-web-5.8.12.jar:5.8.12]
    at org.craftercms.studio.impl.v2.security.UserActivityFilter.doFilterInternal(UserActivityFilter.java:72) [classes/:4.1.4E-BETA]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:117) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:126) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:120) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:100) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:164) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.craftercms.studio.impl.v2.security.authentication.basic.ConditionalBasicAuthenticationFilter.doFilterInternal(ConditionalBasicAuthenticationFilter.java:58) [classes/:4.1.4E-BETA]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.authentication.preauth.AbstractPreAuthenticatedProcessingFilter.doFilter(AbstractPreAuthenticatedProcessingFilter.java:150) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.web.filter.CorsFilter.doFilterInternal(CorsFilter.java:91) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.header.HeaderWriterFilter.doHeadersBefore(HeaderWriterFilter.java:82) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:72) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:62) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:117) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.session.DisableEncodeUrlFilter.doFilterInternal(DisableEncodeUrlFilter.java:42) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:225) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:190) [spring-security-web-5.8.12.jar:5.8.12]
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:354) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267) [spring-web-5.3.34.jar:5.3.34]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [catalina.jar:9.0.85]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [catalina.jar:9.0.85]
    at org.craftercms.engine.servlet.filter.ExceptionHandlingFilter.doFilter(ExceptionHandlingFilter.java:55) [classes/:4.1.4E-BETA]
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:354) [spring-web-5.3.34.jar:5.3.34]
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267) [spring-web-5.3.34.jar:5.3.34]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [catalina.jar:9.0.85]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [catalina.jar:9.0.85]

Screenshots and/or videos

No response

[rart]

@jmendeza a couple of details:

• When a site is being duplicated, it seems like the locked status (of the site being duplicated) is preventing non-mutating calls from succeeding.
  • For example, /studio/api/2/publish/status, or as seen on the ticket report get_configuration
  • If anyone is on preview on that site, that would be a source of a bunch of error logs for all get calls
  • Doesn't seem to be necessary/correct to avoid GET calls from succeeding

@yacdaniel @Euquimides overall, with this LOCKED state in mind, we should probably open a new ticket to handle the site in Locked state is indeed locked all across.

[sumerjabri]

@jmendeza please see notes from @rart

[jmendeza]

New tickets will be created to address outstanding issues. Backend changes for this are merged now.