search

ngs-doo / TemplaterExamples

Creating reports in .NET and Java
https://templater.info
The Unlicense
48 stars 27 forks source link

Process method taking too long for large jsons. #40

Closed jmreisswitz closed 1 year ago

jmreisswitz commented 3 years ago

Hello,

I have a complex docx template that runs against a 5,4mb Json data and the "process" method takes more than 2 minutes to generate this report, time that does not match with my application requirements. I'm attaching a zip with the Json (I ran the lib with a Map<String, Object>, converted to this Json and then removed sensitive data from it) I'm using templater version 5.2.0 and java 16.

Is there any way to try to improve this performance?

ActivityTemplate.docx templater_data.zip

zapov commented 3 years ago

Java v5.2.0 process this file in 22 seconds on Java 8. v6.0.0 (to be released soon) does the same in 14 seconds on Java 8 and in 11 seconds on Java 15.

This seems fine to me as it generates 750 pages.

I'm assuming you have some custom plugin causing problems.

If you have a profiler I suggest trying to profile to see where are the hotspots.

zapov commented 3 years ago

There is a new build here: https://github.com/ngs-doo/TemplaterExamples/releases/tag/v6.0.0 which you can use to test the speed of your document without any customization. This finishes in 13 seconds on my computer:

java -jar templater-json.jar ActivityTemplate.docx templater_data.json out.docx
jpweit commented 2 years ago

Hello,

I'm replacing @jmreisswitz in this issue . I updated our version from 2.9.4 to 6.0.0 in our spring boot application, and then i got the following error (when trying to run against the same data):

java.lang.IllegalArgumentException: Comparison method violates its general contract!
    at java.base/java.util.TimSort.mergeHi(TimSort.java:903)
    at java.base/java.util.TimSort.mergeAt(TimSort.java:520)
    at java.base/java.util.TimSort.mergeCollapse(TimSort.java:448)
    at java.base/java.util.TimSort.sort(TimSort.java:245)
    at java.base/java.util.Arrays.sort(Arrays.java:1306)
    at java.base/java.util.ArrayList.sort(ArrayList.java:1721)
    at hr.ngs.templater.di.b(Unknown Source)
    at hr.ngs.templater.di.resize(Unknown Source)
    at hr.ngs.templater.dr.b(Unknown Source)
    at hr.ngs.templater.dm.b(Unknown Source)
    at hr.ngs.templater.dm.b(Unknown Source)
    at hr.ngs.templater.dw.b(Unknown Source)
    at hr.ngs.templater.dw.b(Unknown Source)
    at hr.ngs.templater.ds.b(Unknown Source)
    at hr.ngs.templater.dr.b(Unknown Source)
    at hr.ngs.templater.dm.b(Unknown Source)
    at hr.ngs.templater.dm.b(Unknown Source)
    at hr.ngs.templater.dw.b(Unknown Source)
    at hr.ngs.templater.dw.b(Unknown Source)
    at hr.ngs.templater.ds.b(Unknown Source)
    at hr.ngs.templater.ds.b(Unknown Source)
    at hr.ngs.templater.ds.b(Unknown Source)
    at hr.ngs.templater.ds.b(Unknown Source)
    at hr.ngs.templater.r.process(Unknown Source)
    at com.aegro.sed.report.TemplaterReport.applyTemplaterConversion(TemplaterReport.java:116)
    at com.aegro.sed.report.TemplaterReport.getFile(TemplaterReport.java:63)
    at com.aegro.sed.service.ReportServiceImpl.uploadToS3(ReportServiceImpl.java:203)
    at com.aegro.sed.service.ReportServiceImpl.reportActivities(ReportServiceImpl.java:346)
    at com.aegro.sed.service.ReportServiceImpl$$FastClassBySpringCGLIB$$cd33d1d1.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
    at org.springframework.aop.aspectj.AspectJAfterThrowingAdvice.invoke(AspectJAfterThrowingAdvice.java:64)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89)
    at com.aegro.sed.aop.logging.LoggingAspect.logAround(LoggingAspect.java:57)
    at jdk.internal.reflect.GeneratedMethodAccessor214.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624)
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692)
    at com.aegro.sed.service.ReportServiceImpl$$EnhancerBySpringCGLIB$$bc52c18a.reportActivities(<generated>)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208)
    at jdk.proxy2/jdk.proxy2.$Proxy347.reportActivities(Unknown Source)
    at com.aegro.sed.controller.ReportController.reportActivities(ReportController.java:77)
    at com.aegro.sed.controller.ReportController$$FastClassBySpringCGLIB$$370b2e2b.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89)
    at com.aegro.sed.aop.errors.ControllerAspect.controllerAspect(ControllerAspect.java:104)
    at jdk.internal.reflect.GeneratedMethodAccessor276.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624)
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
    at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:61)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692)
    at com.aegro.sed.controller.ReportController$$EnhancerBySpringCGLIB$$bd3d0fbe.reportActivities(<generated>)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:894)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1063)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:681)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:228)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at io.sentry.spring.SentryUserFilter.doFilterInternal(SentryUserFilter.java:56)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at com.aegro.sed.config.TagRequestFilter.doFilter(TagRequestFilter.java:65)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at com.aegro.sed.config.ResettableInputFilter.doFilter(ResettableInputFilter.java:43)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:327)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:121)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:115)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:126)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:81)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:105)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:149)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.oauth2.provider.authentication.OAuth2AuthenticationProcessingFilter.doFilter(OAuth2AuthenticationProcessingFilter.java:182)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:103)
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:89)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90)
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:110)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:80)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:55)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:211)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:183)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:358)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:271)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:142)
    at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:82)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:96)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at io.sentry.spring.tracing.SentryTracingFilter.doFilterInternal(SentryTracingFilter.java:69)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at io.sentry.spring.SentrySpringFilter.doFilterInternal(SentrySpringFilter.java:57)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1723)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.base/java.lang.Thread.run(Thread.java:831)

Do you have any idea how to solve it?

zapov commented 2 years ago

Hi,

can you make a small reproducible? I'm assuming same thing happens on v6.1.0

zapov commented 2 years ago

I think I have an idea what would causing this sorting issue. Can you please try the build with a fix: https://tools.dsl-platform.com/templater-6.1.1.jar

zapov commented 2 years ago

@jpweit did you try it with v6.1.1 ?

jpweit commented 2 years ago

Sorry for the delay. I tested with the version 6.1.1, which ended up with the previous error, but it didn't fix the original problem, it still takes more than 2 minutes to process.

zapov commented 2 years ago

Hi @jpweit

I will assume you meant that it fixed the previous error? Or you meant what you wrote (that it didn't fix it) with previous error being Comparison method? I will also assume that you are using some other template with some other data? Can you run the java for the provided docx and json (in the start of the issue) as I wrote above

java -jar templater-json.jar ActivityTemplate.docx templater_data.json out.docx

just to confirm what times you have on your end? I even ran it with -Xmx2048m to make sure its not a memory problem and it worked fine. You can try setting Xmx limit yourself, it might help to prevent GC frenzy.

Common case when Templater runs "slowly" is when you have a "bad template", meaning you've set it up incorrectly. Templater Editor will check if you template is valid, but I would need to have your actual template and data inputs.

zapov commented 2 years ago

Hi @jpweit and @jmreisswitz

We've released v7 which further optimizes this use case. If you use library from https://github.com/ngs-doo/TemplaterExamples/releases/tag/v7.0.0 on your provided template and data it finishes in 5 seconds on Java 11.

But since this was never the problem (it was 12 seconds on v6) I'm inclined to close this issue unless you can provide an actual reproducible (template and json) which will run slowly with the vanilla builds.

zapov commented 1 year ago

I'll close this as this sounds like a problem with plugin, not Templater.

If you manage to reproduce it with vanilla version please reopen