search

mapfish / mapfish-print

A component of MapFish for printing templated cartographic maps. This module is the Java serverside module.
http://mapfish.github.io/mapfish-print-doc/
BSD 2-Clause "Simplified" License
184 stars 417 forks source link

MapFishPrint suddently becomes realy slow (completely unusable) #221

Closed sbrunner closed 9 years ago

sbrunner commented 9 years ago

CPU => 160 %

top: 27071 tomcat 20 0 1224m 827m 40m S 162.9 20.9 8:17.75 java

Logs:

11:45:00.565 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/37/23.png
11:45:00.565 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/37/23.png
11:45:01.877 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/37/24.png
11:45:01.877 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/37/24.png
11:45:03.074 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/37/25.png
11:45:03.074 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/37/25.png
11:45:04.148 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/21.png
11:45:04.148 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/21.png
11:45:04.710 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/22.png
11:45:06.012 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/22.png
11:45:06.707 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/23.png
11:45:06.707 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/23.png
11:45:12.998 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/24.png
11:45:13.534 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/24.png
11:45:15.068 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/25.png
11:45:15.650 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/36/25.png
11:45:18.284 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/21.png
11:45:18.284 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/21.png

11:45:50.448 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/22.png
11:45:50.449 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/22.png
11:45:52.787 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/23.png
11:45:52.787 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/23.png
11:45:57.848 [ForkJoinPool-1-worker-5] INFO  o.m.p.processor.ProcessorGraphNode - Succeeded in executing process: CreateScalebarProcessor
11:45:57.849 [ForkJoinPool-1-worker-5] DEBUG o.m.p.processor.ProcessorGraphNode - Time taken to run processor: 'class org.mapfish.print.processor.map.scalebar.CreateScalebarProcessor' was 69172 ms
11:45:58.596 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/24.png
11:45:58.597 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/24.png
11:45:58.599 [ForkJoinPool-1-worker-3] INFO  o.m.p.processor.ProcessorGraphNode - Succeeded in executing process: CreateNorthArrowProcessor
11:45:58.600 [ForkJoinPool-1-worker-3] DEBUG o.m.p.processor.ProcessorGraphNode - Time taken to run processor: 'class org.mapfish.print.processor.map.CreateNorthArrowProcessor' was 69922 ms
11:46:02.746 [ForkJoinPool-1-worker-7] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/25.png
11:46:02.751 [ForkJoinPool-1-worker-7] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/25.png
11:46:17.378 [ForkJoinPool-1-worker-1] INFO  o.m.p.p.jasper.JasperReportBuilder - Report built in 88701ms.
11:46:17.379 [ForkJoinPool-1-worker-1] INFO  o.m.p.processor.ProcessorGraphNode - Succeeded in executing process: JasperReportBuilder(/srv/tomcat/tomcat1/webapps/print-sbrunner/print-apps/demo/.)
11:46:17.379 [ForkJoinPool-1-worker-1] DEBUG o.m.p.processor.ProcessorGraphNode - Time taken to run processor: 'class org.mapfish.print.processor.jasper.JasperReportBuilder' was 88704 ms
tsauerwein commented 9 years ago

Might be related to #157

jesseeichar commented 9 years ago

CAn you do a jstack dump when this happens?

full process is as follows:

  1. sudo su tomcat
  2. jps
  3. jstack > /tmp/mapfish-stack.txt

On Thu, Mar 19, 2015 at 11:50 AM, Tobias Sauerwein <notifications@github.com

wrote:

Might be related to #157 https://github.com/mapfish/mapfish-print/issues/157

— Reply to this email directly or view it on GitHub https://github.com/mapfish/mapfish-print/issues/221#issuecomment-83502337 .

sbrunner commented 9 years ago

Not directly, #157 is an improvement, and this one is an issue ...

sbrunner commented 9 years ago

Thanks Jessy, I will do it the next time I have this issue :-)

sbrunner commented 9 years ago

jstack result:

2015-03-19 13:13:54
Full thread dump OpenJDK 64-Bit Server VM (24.75-b04 mixed mode):

"Attach Listener" daemon prio=10 tid=0x00000000024ad800 nid=0x14ec waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"http-8080-17" daemon prio=10 tid=0x00007f5664d55000 nid=0x14d1 waiting for monitor entry [0x00007f565edaf000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.tomcat.util.http.FastHttpDateFormat.getCurrentDate(FastHttpDateFormat.java:114)
    - waiting to lock <0x00000000f1640f70> (a java.text.SimpleDateFormat)
    at org.apache.coyote.http11.Http11Processor.prepareResponse(Http11Processor.java:1604)
    at org.apache.coyote.http11.Http11Processor.action(Http11Processor.java:956)
    at org.apache.coyote.Response.action(Response.java:183)
    at org.apache.coyote.Response.sendHeaders(Response.java:379)
    at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:314)
    at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:274)
    at org.apache.catalina.connector.CoyoteWriter.close(CoyoteWriter.java:108)
    at org.springframework.security.web.context.SaveContextOnUpdateOrErrorResponseWrapper$SaveContextPrintWriter.close(SaveContextOnUpdateOrErrorResponseWrapper.java:212)
    at org.mapfish.print.servlet.MapPrinterServlet.getStatus(MapPrinterServlet.java:271)
    at org.mapfish.print.servlet.MapPrinterServlet.getStatusSpecificAppId(MapPrinterServlet.java:218)
    at sun.reflect.GeneratedMethodAccessor322.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:176)
    at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:440)
    at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:428)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:953)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:844)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:829)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:97)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:150)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.access.channel.ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:144)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:343)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:260)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.mapfish.print.servlet.RequestSizeFilter.doFilter(RequestSizeFilter.java:59)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-16" daemon prio=10 tid=0x00007f56652f5800 nid=0x14c9 waiting for monitor entry [0x00007f56693ec000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
    at org.apache.log4j.Category.forcedLog(Category.java:391)
    at org.apache.log4j.Category.log(Category.java:856)
    at org.apache.juli.logging.impl.Log4JLogger.error(Log4JLogger.java:257)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:274)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-15" daemon prio=10 tid=0x00007f5666c01000 nid=0x14c8 waiting for monitor entry [0x00007f565d9ad000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
    at org.apache.log4j.Category.forcedLog(Category.java:391)
    at org.apache.log4j.Category.log(Category.java:856)
    at org.apache.juli.logging.impl.Log4JLogger.error(Log4JLogger.java:257)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:274)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-14" daemon prio=10 tid=0x0000000000f6b000 nid=0x14c7 waiting for monitor entry [0x00007f565ecb0000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
    at org.apache.log4j.Category.forcedLog(Category.java:391)
    at org.apache.log4j.Category.log(Category.java:856)
    at org.apache.juli.logging.impl.Log4JLogger.error(Log4JLogger.java:257)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:274)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-13" daemon prio=10 tid=0x0000000002341800 nid=0x14b7 waiting for monitor entry [0x00007f565d7ab000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
    at org.apache.log4j.Category.forcedLog(Category.java:391)
    at org.apache.log4j.Category.log(Category.java:856)
    at org.apache.juli.logging.impl.Log4JLogger.error(Log4JLogger.java:257)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:274)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-12" daemon prio=10 tid=0x00000000022fa000 nid=0x14b4 waiting for monitor entry [0x00007f56696ef000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
    at org.apache.log4j.Category.forcedLog(Category.java:391)
    at org.apache.log4j.Category.log(Category.java:856)
    at org.apache.juli.logging.impl.Log4JLogger.error(Log4JLogger.java:257)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:274)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-9" daemon prio=10 tid=0x0000000001656000 nid=0x149c waiting for monitor entry [0x00007f565c6a8000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.tomcat.util.http.FastHttpDateFormat.getCurrentDate(FastHttpDateFormat.java:114)
    - waiting to lock <0x00000000f1640f70> (a java.text.SimpleDateFormat)
    at org.apache.coyote.http11.Http11Processor.prepareResponse(Http11Processor.java:1604)
    at org.apache.coyote.http11.Http11Processor.action(Http11Processor.java:956)
    at org.apache.coyote.Response.action(Response.java:183)
    at org.apache.coyote.Response.sendHeaders(Response.java:379)
    at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:314)
    at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:274)
    at org.apache.catalina.connector.CoyoteWriter.close(CoyoteWriter.java:108)
    at org.springframework.security.web.context.SaveContextOnUpdateOrErrorResponseWrapper$SaveContextPrintWriter.close(SaveContextOnUpdateOrErrorResponseWrapper.java:212)
    at org.mapfish.print.servlet.MapPrinterServlet.getStatus(MapPrinterServlet.java:271)
    at org.mapfish.print.servlet.MapPrinterServlet.getStatusSpecificAppId(MapPrinterServlet.java:218)
    at sun.reflect.GeneratedMethodAccessor322.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:176)
    at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:440)
    at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:428)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:953)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:844)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:829)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:97)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:150)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.access.channel.ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:144)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:343)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:260)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.mapfish.print.servlet.RequestSizeFilter.doFilter(RequestSizeFilter.java:59)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-8" daemon prio=10 tid=0x0000000002d60000 nid=0x1489 runnable [0x00007f565c0a3000]
   java.lang.Thread.State: RUNNABLE
    at java.lang.ClassLoader.findLoadedClass0(Native Method)
    at java.lang.ClassLoader.findLoadedClass(ClassLoader.java:1093)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:407)
    - locked <0x00000000faae1398> (a java.lang.Object)
    at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:412)
    - locked <0x00000000f01d2120> (a org.apache.catalina.loader.StandardClassLoader)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
    at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
    at org.apache.log4j.Category.forcedLog(Category.java:391)
    at org.apache.log4j.Category.log(Category.java:856)
    at org.apache.juli.logging.impl.Log4JLogger.error(Log4JLogger.java:257)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:274)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-7" daemon prio=10 tid=0x0000000001c2f800 nid=0x1480 waiting on condition [0x00007f565c1a1000]
   java.lang.Thread.State: RUNNABLE
    at sun.misc.Unsafe.defineClass(Native Method)
    at sun.reflect.ClassDefiner.defineClass(ClassDefiner.java:63)
    at sun.reflect.MethodAccessorGenerator$1.run(MethodAccessorGenerator.java:399)
    at sun.reflect.MethodAccessorGenerator$1.run(MethodAccessorGenerator.java:396)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.reflect.MethodAccessorGenerator.generate(MethodAccessorGenerator.java:395)
    at sun.reflect.MethodAccessorGenerator.generateConstructor(MethodAccessorGenerator.java:94)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:48)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
    at java.lang.Class.newInstance(Class.java:379)
    at java.util.ResourceBundle$Control.newBundle(ResourceBundle.java:2572)
    at java.util.ResourceBundle.loadBundle(ResourceBundle.java:1436)
    at java.util.ResourceBundle.findBundle(ResourceBundle.java:1400)
    at java.util.ResourceBundle.findBundle(ResourceBundle.java:1354)
    at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:1296)
    at java.util.ResourceBundle.getBundle(ResourceBundle.java:841)
    at sun.util.resources.LocaleData$1.run(LocaleData.java:142)
    at sun.util.resources.LocaleData$1.run(LocaleData.java:140)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.util.resources.LocaleData.getBundle(LocaleData.java:140)
    at sun.util.resources.LocaleData.getTimeZoneNames(LocaleData.java:112)
    at sun.util.TimeZoneNameUtility.getBundle(TimeZoneNameUtility.java:132)
    at sun.util.TimeZoneNameUtility.retrieveDisplayNames(TimeZoneNameUtility.java:98)
    at java.util.TimeZone.getDisplayNames(TimeZone.java:458)
    at java.util.TimeZone.getDisplayName(TimeZone.java:409)
    at java.text.SimpleDateFormat.subFormat(SimpleDateFormat.java:1213)
    at java.text.SimpleDateFormat.format(SimpleDateFormat.java:978)
    at java.text.SimpleDateFormat.format(SimpleDateFormat.java:948)
    at java.text.DateFormat.format(DateFormat.java:336)
    at org.apache.tomcat.util.http.FastHttpDateFormat.getCurrentDate(FastHttpDateFormat.java:115)
    - locked <0x00000000f1640f70> (a java.text.SimpleDateFormat)
    at org.apache.coyote.http11.Http11Processor.prepareResponse(Http11Processor.java:1604)
    at org.apache.coyote.http11.Http11Processor.action(Http11Processor.java:956)
    at org.apache.coyote.Response.action(Response.java:183)
    at org.apache.coyote.Response.sendHeaders(Response.java:379)
    at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:314)
    at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:274)
    at org.apache.catalina.connector.CoyoteWriter.close(CoyoteWriter.java:108)
    at org.springframework.security.web.context.SaveContextOnUpdateOrErrorResponseWrapper$SaveContextPrintWriter.close(SaveContextOnUpdateOrErrorResponseWrapper.java:212)
    at org.mapfish.print.servlet.MapPrinterServlet.getStatus(MapPrinterServlet.java:271)
    at org.mapfish.print.servlet.MapPrinterServlet.getStatusSpecificAppId(MapPrinterServlet.java:218)
    at sun.reflect.GeneratedMethodAccessor322.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:176)
    at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:440)
    at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:428)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:953)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:844)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:829)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:97)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:150)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.access.channel.ChannelProcessingFilter.doFilter(ChannelProcessingFilter.java:144)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:343)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:260)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.mapfish.print.servlet.RequestSizeFilter.doFilter(RequestSizeFilter.java:59)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"Batik CleanerThread" daemon prio=10 tid=0x00007f566541f000 nid=0x147c in Object.wait() [0x00007f565c2a6000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000fa410a60> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000fa410a60> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.apache.batik.util.CleanerThread.run(CleanerThread.java:106)

"http-8080-6" daemon prio=10 tid=0x0000000001c31800 nid=0x147b waiting for monitor entry [0x00007f565c3a7000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
    at org.apache.log4j.Category.forcedLog(Category.java:391)
    at org.apache.log4j.Category.log(Category.java:856)
    at org.apache.juli.logging.impl.Log4JLogger.error(Log4JLogger.java:257)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:274)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-5" daemon prio=10 tid=0x00000000026dc000 nid=0x147a waiting for monitor entry [0x00007f565c4a8000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
    at org.apache.log4j.Category.forcedLog(Category.java:391)
    at org.apache.log4j.Category.log(Category.java:856)
    at org.apache.juli.logging.impl.Log4JLogger.error(Log4JLogger.java:257)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:873)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"http-8080-4" daemon prio=10 tid=0x000000000154a000 nid=0x1479 waiting for monitor entry [0x00007f565c5a9000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
    at org.apache.log4j.Category.forcedLog(Category.java:391)
    at org.apache.log4j.Category.log(Category.java:856)
    at org.apache.juli.logging.impl.Log4JLogger.error(Log4JLogger.java:257)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:274)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
    at java.lang.Thread.run(Thread.java:745)

"ForkJoinPool-1-worker-8" daemon prio=10 tid=0x0000000001655800 nid=0x1476 waiting on condition [0x00007f56692eb000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000f833ca70> (a jsr166y.ForkJoinPool)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
    at jsr166y.ForkJoinPool.tryAwaitWork(ForkJoinPool.java:835)
    at jsr166y.ForkJoinPool.work(ForkJoinPool.java:618)
    at jsr166y.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:369)

"WeakCollectionCleaner" daemon prio=10 tid=0x00007f566cf2c000 nid=0x146d in Object.wait() [0x00007f565ebaf000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f8ee87a8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f8ee87a8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.geotools.util.WeakCollectionCleaner.run(WeakCollectionCleaner.java:77)

"GT authority factory disposer" daemon prio=10 tid=0x00007f566ca53000 nid=0x146c in Object.wait() [0x00007f5668ee7000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f8ee89e0> (a java.util.TaskQueue)
    at java.util.TimerThread.mainLoop(Timer.java:552)
    - locked <0x00000000f8ee89e0> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Timer.java:505)

"PrintJobManager-1" daemon prio=10 tid=0x00007f566c7a2800 nid=0x146a waiting on condition [0x00007f56691ea000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000f84d3fb0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
    at java.util.concurrent.PriorityBlockingQueue.take(PriorityBlockingQueue.java:539)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

"Post result to registry" daemon prio=10 tid=0x00007f566cd08800 nid=0x1448 waiting on condition [0x00007f5668de6000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000f84d4108> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

"Batik CleanerThread" daemon prio=10 tid=0x00007f5666bed800 nid=0x12bf in Object.wait() [0x00007f565d8ac000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f7d46a78> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f7d46a78> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.apache.batik.util.CleanerThread.run(CleanerThread.java:106)

"WeakCollectionCleaner" daemon prio=10 tid=0x00007f5665191000 nid=0x12b4 in Object.wait() [0x00007f5668ce5000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f67c08f0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f67c08f0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.geotools.util.WeakCollectionCleaner.run(WeakCollectionCleaner.java:77)

"GT authority factory disposer" daemon prio=10 tid=0x00007f5665549800 nid=0x12b3 in Object.wait() [0x00007f566a9f2000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f67aa210> (a java.util.TaskQueue)
    at java.util.TimerThread.mainLoop(Timer.java:552)
    - locked <0x00000000f67aa210> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Timer.java:505)

"Batik CleanerThread" daemon prio=10 tid=0x00007f5664906000 nid=0x1110 in Object.wait() [0x00007f56734e2000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f5f72d28> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f5f72d28> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.apache.batik.util.CleanerThread.run(CleanerThread.java:106)

"WeakCollectionCleaner" daemon prio=10 tid=0x00007f5665452000 nid=0x1103 in Object.wait() [0x00007f566a8f1000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f47916a8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f47916a8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.geotools.util.WeakCollectionCleaner.run(WeakCollectionCleaner.java:77)

"GT authority factory disposer" daemon prio=10 tid=0x00007f5664da7000 nid=0x1102 in Object.wait() [0x00007f56690e9000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f47919c0> (a java.util.TaskQueue)
    at java.util.TimerThread.mainLoop(Timer.java:552)
    - locked <0x00000000f47919c0> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Timer.java:505)

"Batik CleanerThread" daemon prio=10 tid=0x00007f56647e7000 nid=0x7e99 in Object.wait() [0x00007f566877b000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f40bd958> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f40bd958> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.apache.batik.util.CleanerThread.run(CleanerThread.java:106)

"WeakCollectionCleaner" daemon prio=10 tid=0x00007f566c708800 nid=0x7e8c in Object.wait() [0x00007f5668fe8000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f3b01180> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f3b01180> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.geotools.util.WeakCollectionCleaner.run(WeakCollectionCleaner.java:77)

"Batik CleanerThread" daemon prio=10 tid=0x00007f566ceed800 nid=0x7d37 in Object.wait() [0x00007f566887c000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f329fc68> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f329fc68> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.apache.batik.util.CleanerThread.run(CleanerThread.java:106)

"Java2D Disposer" daemon prio=10 tid=0x0000000000f57800 nid=0x7d36 in Object.wait() [0x00007f5668be4000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f3221a00> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f3221a00> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at sun.java2d.Disposer.run(Disposer.java:145)
    at java.lang.Thread.run(Thread.java:745)

"WeakCollectionCleaner" daemon prio=10 tid=0x00007f566c9e8000 nid=0x7d2a in Object.wait() [0x00007f56697f0000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f26b3960> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f26b3960> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at org.geotools.util.WeakCollectionCleaner.run(WeakCollectionCleaner.java:77)

"http-8080-Acceptor-0" daemon prio=10 tid=0x00007f56650d3800 nid=0x77d2 runnable [0x00007f566af0b000]
   java.lang.Thread.State: RUNNABLE
    at java.net.PlainSocketImpl.socketAccept(Native Method)
    at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
    at java.net.ServerSocket.implAccept(ServerSocket.java:530)
    at java.net.ServerSocket.accept(ServerSocket.java:498)
    at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(DefaultServerSocketFactory.java:61)
    at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:352)
    at java.lang.Thread.run(Thread.java:745)

"TP-Monitor" daemon prio=10 tid=0x00007f5664f0d800 nid=0x77d1 in Object.wait() [0x00007f566b00c000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f14d6750> (a org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable)
    at org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable.run(ThreadPool.java:565)
    - locked <0x00000000f14d6750> (a org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable)
    at java.lang.Thread.run(Thread.java:745)

"TP-Processor4" daemon prio=10 tid=0x00007f566592c800 nid=0x77d0 runnable [0x00007f566b10d000]
   java.lang.Thread.State: RUNNABLE
    at java.net.PlainSocketImpl.socketAccept(Native Method)
    at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
    at java.net.ServerSocket.implAccept(ServerSocket.java:530)
    at java.net.ServerSocket.accept(ServerSocket.java:498)
    at org.apache.jk.common.ChannelSocket.accept(ChannelSocket.java:311)
    at org.apache.jk.common.ChannelSocket.acceptConnections(ChannelSocket.java:668)
    at org.apache.jk.common.ChannelSocket$SocketAcceptor.runIt(ChannelSocket.java:879)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
    at java.lang.Thread.run(Thread.java:745)

"TP-Processor3" daemon prio=10 tid=0x0000000001414000 nid=0x77cf in Object.wait() [0x00007f5670112000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f14d61b0> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
    at java.lang.Object.wait(Object.java:503)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:662)
    - locked <0x00000000f14d61b0> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
    at java.lang.Thread.run(Thread.java:745)

"TP-Processor2" daemon prio=10 tid=0x0000000001413000 nid=0x77ce in Object.wait() [0x00007f5673922000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f14d6390> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
    at java.lang.Object.wait(Object.java:503)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:662)
    - locked <0x00000000f14d6390> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
    at java.lang.Thread.run(Thread.java:745)

"TP-Processor1" daemon prio=10 tid=0x0000000002639000 nid=0x77cd in Object.wait() [0x00007f5673a23000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f14d6570> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
    at java.lang.Object.wait(Object.java:503)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:662)
    - locked <0x00000000f14d6570> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
    at java.lang.Thread.run(Thread.java:745)

"ContainerBackgroundProcessor[StandardEngine[Catalina]]" daemon prio=10 tid=0x0000000002e21000 nid=0x77cc waiting on condition [0x00007f5673c0a000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1631)
    at java.lang.Thread.run(Thread.java:745)

"Post result to registry" daemon prio=10 tid=0x0000000004241000 nid=0x77cb waiting on condition [0x00007f566b20e000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000f14c3c00> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

"Post result to registry" daemon prio=10 tid=0x0000000001c77800 nid=0x77c8 waiting on condition [0x00007f566b30f000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000f0f54d50> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

"Service Thread" daemon prio=10 tid=0x0000000000c9e000 nid=0x77a6 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x0000000000c9b000 nid=0x77a5 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x0000000000c98000 nid=0x77a4 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x0000000000c96000 nid=0x77a3 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x0000000000c62000 nid=0x77a2 in Object.wait() [0x00007f5676144000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f00c84c0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000f00c84c0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" daemon prio=10 tid=0x0000000000c60000 nid=0x77a1 in Object.wait() [0x00007f5676245000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f00c8250> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:503)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
    - locked <0x00000000f00c8250> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x0000000000bf4800 nid=0x7789 runnable [0x00007f567e869000]
   java.lang.Thread.State: RUNNABLE
    at java.net.PlainSocketImpl.socketAccept(Native Method)
    at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
    at java.net.ServerSocket.implAccept(ServerSocket.java:530)
    at java.net.ServerSocket.accept(ServerSocket.java:498)
    at org.apache.catalina.core.StandardServer.await(StandardServer.java:431)
    at org.apache.catalina.startup.Catalina.await(Catalina.java:676)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:628)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)

"VM Thread" prio=10 tid=0x0000000000c5b800 nid=0x77a0 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x0000000000c0a800 nid=0x778d runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x0000000000c0c000 nid=0x778f runnable 

"VM Periodic Task Thread" prio=10 tid=0x0000000000ca9000 nid=0x77a7 waiting on condition 

JNI global references: 433
sbrunner commented 9 years ago

And the related log:

13:11:28.470 [ForkJoinPool-1-worker-6] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/23.png
13:11:29.641 [ForkJoinPool-1-worker-6] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/23.png
13:11:52.546 [ForkJoinPool-1-worker-6] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/24.png
13:11:52.547 [ForkJoinPool-1-worker-6] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/24.png
13:11:56.353 [ForkJoinPool-1-worker-6] DEBUG o.m.print.map.tiled.TileLoaderTask - 
        GET -- http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/25.png
13:11:57.060 [ForkJoinPool-1-worker-6] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://ows.asitvd.ch/wmts/1.0.0/asitvd.fond_couleur/default/default/0/21781/19/35/25.png

13:12:01.134 [ForkJoinPool-1-worker-5] INFO  o.m.p.processor.ProcessorGraphNode - Succeeded in executing process: CreateScalebarProcessor
13:12:01.134 [ForkJoinPool-1-worker-5] DEBUG o.m.p.processor.ProcessorGraphNode - Time taken to run processor: 'class org.mapfish.print.processor.map.scalebar.CreateScalebarProcessor' was 50521 ms
13:12:01.135 [ForkJoinPool-1-worker-3] INFO  o.m.p.processor.ProcessorGraphNode - Succeeded in executing process: CreateNorthArrowProcessor
13:12:01.136 [ForkJoinPool-1-worker-3] DEBUG o.m.p.processor.ProcessorGraphNode - Time taken to run processor: 'class org.mapfish.print.processor.map.CreateNorthArrowProcessor' was 50512 ms
13:12:04.360 [ForkJoinPool-1-worker-1] INFO  o.m.p.p.jasper.JasperReportBuilder - Report built in 53744ms.
13:12:04.360 [ForkJoinPool-1-worker-1] INFO  o.m.p.processor.ProcessorGraphNode - Succeeded in executing process: JasperReportBuilder(/srv/tomcat/tomcat1/webapps/print-sbrunner/print-apps/demo/.)
13:12:04.360 [ForkJoinPool-1-worker-1] DEBUG o.m.p.processor.ProcessorGraphNode - Time taken to run processor: 'class org.mapfish.print.processor.jasper.JasperReportBuilder' was 53749 ms
13:12:17.145 [ForkJoinPool-1-worker-6] DEBUG o.m.print.map.style.StyleParser - Content is not allowed in prolog.
13:12:17.149 [ForkJoinPool-1-worker-6] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: raster
13:12:17.151 [ForkJoinPool-1-worker-6] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: raster
13:12:25.264 [ForkJoinPool-1-worker-6] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: http://geomapfish.demo-camptocamp.com/sbrunner/wsgi/mapserv_proxy?TRANSPARENT=true&BBOX=532210.4166666666%2C142093.75%2C551789.5833333333%2C165906.25&VERSION=1.1.1&FORMAT=image%2Fpng&SERVICE=WMS&HEIGHT=2381&REQUEST=GetMap&LAYERS=fuel&STYLES=&SRS=EPSG%3A21781&WIDTH=1957
13:12:25.554 [ForkJoinPool-1-worker-6] DEBUG o.m.print.map.style.StyleParser - Content is not allowed in prolog.
13:12:25.555 [ForkJoinPool-1-worker-6] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: raster
13:12:25.555 [ForkJoinPool-1-worker-6] DEBUG o.m.p.h.ConfigFileResolvingHttpRequestFactory - Executing http request: raster
13:12:31.732 [ForkJoinPool-1-worker-6] INFO  o.m.p.processor.ProcessorGraphNode - Succeeded in executing process: CreateMapProcessor
13:12:31.732 [ForkJoinPool-1-worker-6] DEBUG o.m.p.processor.ProcessorGraphNode - Time taken to run processor: 'class org.mapfish.print.processor.map.CreateMapProcessor' was 81109 ms
13:12:31.732 [ForkJoinPool-1-worker-1] DEBUG o.m.p.p.ProcessorDependencyGraph - Finished executing processor graph: 
+ JasperReportBuilder(/srv/tomcat/tomcat1/webapps/print-sbrunner/print-apps/demo/.)
+ LegendProcessor
+ CreateNorthArrowProcessor
+ CreateScalebarProcessor
+ CreateMapProcessor
+ DataSourceProcessor
13:12:31.734 [PrintJobManager-1] INFO  o.mapfish.print.output.ValuesLogger - 
This log message details the parameters available for use in the Jasper templates for
  Mapfish Template: A4 portrait
  Jasper Template name: A4_Portrait.jrxml
  The following parameters are available for use in the templates: 
    * layerGraphics (java.util.ArrayList)
    * pdfConfig (org.mapfish.print.config.PDFConfig)
    * scalebarSubReport (java.lang.String)
    * graphic (java.net.URI)
    * northArrowSubReport (java.lang.String)
    * numberOfLegendRows (java.lang.Integer)
    * jrDataSource (net.sf.jasperreports.engine.JREmptyDataSource)
      - This value is a Jasper Reports DataSource and thus can be passed to a subtemplate as a DataSource and used in the subtemplate's detail band.
      - This datasource is not a type that can be introspected but it can be used in a detail section of sub-template if the structure is known.
    * mapSubReport (java.lang.String)
    * clientHttpRequestFactory (org.mapfish.print.http.ConfigFileResolvingHttpRequestFactory)
    * template (org.mapfish.print.config.Template)
    * tempTaskDirectory (java.io.File)
    * legend (net.sf.jasperreports.engine.data.JRTableModelDataSource)
      - This value is a Jasper Reports DataSource and thus can be passed to a subtemplate as a DataSource and used in the subtemplate's detail band.
      - This datasource is not a type that can be introspected but it can be used in a detail section of sub-template if the structure is known.
    * comments (java.lang.String)
    * legendSubReport (java.lang.String)
    * requestHeaders (org.mapfish.print.attribute.HttpRequestHeadersAttribute$Value)
    * scalebar (org.mapfish.print.attribute.ScalebarAttribute$ScalebarAttributeValues)
    * mapContext (org.mapfish.print.attribute.map.MapfishMapContext)
    * title (java.lang.String)
    * map (org.mapfish.print.attribute.map.MapAttribute$MapAttributeValues)
    * debug (java.lang.Integer)
    * SUBREPORT_DIR (java.lang.String)
    * datasource (org.mapfish.print.attribute.DataSourceAttribute$DataSourceAttributeValue)
    * northArrow (org.mapfish.print.attribute.NorthArrowAttribute$NorthArrowAttributeValues)

13:12:39.471 [PrintJobManager-1] DEBUG o.mapfish.print.servlet.job.PrintJob - Print Job 13f3b4a1-bce9-4543-89ea-813121f3420b@9e9572f2-1a82-41f4-bf60-96dbac8d0e83 completed in 95264ms
Exception in thread "http-8080-1" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-3" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-10" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-2" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-11" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-8" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-5" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-4" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-16" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-14" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-12" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-6" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-7" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-9" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-13" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-17" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-15" java.lang.OutOfMemoryError: PermGen space
tsauerwein commented 9 years ago 
...
Exception in thread "http-8080-17" java.lang.OutOfMemoryError: PermGen space
Exception in thread "http-8080-15" java.lang.OutOfMemoryError: PermGen space

I re-run our load-balancing tests with jMeter to make sure we didn't introduce memory leaks. I used the configuration of demo_geomapfish and simulated for more than 1 hour 100 users which continuously send print requests, poll the status and request the report. This didn't reveal any memory problems (except my hard drive was getting pretty filled up after more than 50 000 reports ;).

BUT we do have a PermGen memory leak! Apparently the classes are not unloaded properly when redeploying. It is pretty visible in these VisualVM charts:

mfp-permgen-space

In the Tomcat logs are some hints:

25-Mar-2015 14:06:03.974 WARNING [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.loader.WebappClassLoader.clearReferencesJdbc The web application [/print-servlet-3.3-SNAPSHOT] registered the JDBC driver [org.hsqldb.jdbc.JDBCDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
25-Mar-2015 14:06:03.974 WARNING [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.loader.WebappClassLoader.clearReferencesThreads The web application [/print-servlet-3.3-SNAPSHOT] appears to have started a thread named [GT authority factory disposer] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Object.wait(Native Method)
 java.util.TimerThread.mainLoop(Timer.java:552)
 java.util.TimerThread.run(Timer.java:505)
25-Mar-2015 14:06:03.974 WARNING [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.loader.WebappClassLoader.clearReferencesThreads The web application [/print-servlet-3.3-SNAPSHOT] appears to have started a thread named [WeakCollectionCleaner] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Object.wait(Native Method)
 java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
 java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
 org.geotools.util.WeakCollectionCleaner.run(WeakCollectionCleaner.java:77)
25-Mar-2015 14:06:03.974 WARNING [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.loader.WebappClassLoader.clearReferencesThreads The web application [/print-servlet-3.3-SNAPSHOT] appears to have started a thread named [Batik CleanerThread] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Object.wait(Native Method)
 java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
 java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
 org.apache.batik.util.CleanerThread.run(CleanerThread.java:106)
25-Mar-2015 14:06:03.975 SEVERE [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.loader.WebappClassLoader.checkThreadLocalMapForLeaks The web application [/print-servlet-3.3-SNAPSHOT] created a ThreadLocal with key of type [java.lang.InheritableThreadLocal] (value [java.lang.InheritableThreadLocal@2d042d51]) and a value of type [org.mapfish.print.config.Configuration] (value [org.mapfish.print.config.Configuration@6d3b37ed]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
25-Mar-2015 14:06:03.975 SEVERE [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.loader.WebappClassLoader.checkThreadLocalMapForLeaks The web application [/print-servlet-3.3-SNAPSHOT] created a ThreadLocal with key of type [java.lang.InheritableThreadLocal] (value [java.lang.InheritableThreadLocal@2d042d51]) and a value of type [org.mapfish.print.config.Configuration] (value [org.mapfish.print.config.Configuration@6d3b37ed]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
25-Mar-2015 14:06:03.975 SEVERE [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.loader.WebappClassLoader.checkThreadLocalMapForLeaks The web application [/print-servlet-3.3-SNAPSHOT] created a ThreadLocal with key of type [java.lang.InheritableThreadLocal] (value [java.lang.InheritableThreadLocal@2d042d51]) and a value of type [org.mapfish.print.config.Configuration] (value [org.mapfish.print.config.Configuration@6d3b37ed]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
25-Mar-2015 14:06:03.975 SEVERE [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.loader.WebappClassLoader.checkThreadLocalMapForLeaks The web application [/print-servlet-3.3-SNAPSHOT] created a ThreadLocal with key of type [java.lang.InheritableThreadLocal] (value [java.lang.InheritableThreadLocal@2d042d51]) and a value of type [org.mapfish.print.config.Configuration] (value [org.mapfish.print.config.Configuration@6d3b37ed]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.

@sbrunner The work around for now is to restart Tomcat when re-deploying. This clears the PermGen space. @jesseeichar Do you have any experience with these kind of problems? What could we do?

sbrunner commented 9 years ago

Thanks @tsauerwein for your investigation :-)

jesseeichar commented 9 years ago

I never deploy a server without restarting because it is very easy to make a mistake where the classpath cannot be re-loaded by the JVM. The primary cause is use of static variables in an application but there can be other ways to cause this problem as well.

The problem if you reuse 3rd party libraries is that you can't fix these types of problems if they occur in one of those libraries.

There is some I found when googling for example some people think classes can never be reloaded but this is not the case, if the application is carefully crafted they can be. But it is non-trivial.

Here are some resources I found:

A good blog which explains common causes and possible solutions: http://javarevisited.blogspot.fr/2012/01/tomcat-javalangoutofmemoryerror-permgen.html

Stackoverflow questions: http://stackoverflow.com/questions/2344964/when-and-how-is-a-java-classloader-marked-for-garbage-collection http://stackoverflow.com/questions/660437/what-makes-hot-deployment-a-hard-problem

Jesse

On Wed, Mar 25, 2015 at 2:56 PM, Stéphane Brunner notifications@github.com wrote:

Thanks @tsauerwein https://github.com/tsauerwein for your investigation :-)

— Reply to this email directly or view it on GitHub https://github.com/mapfish/mapfish-print/issues/221#issuecomment-86038541 .

sbrunner commented 9 years ago

Than do we want to fix those issues ok define that we should to restart tomcat after each deploy ?

jesseeichar commented 9 years ago

+1 for restart after deploy. If start-up time is an issue we can look at ways to improve it.

Jesse

On Thu, Mar 26, 2015 at 5:38 PM, Stéphane Brunner notifications@github.com wrote:

Than do we want to fix those issues ok define that we should to restart tomcat after each deploy ?

— Reply to this email directly or view it on GitHub https://github.com/mapfish/mapfish-print/issues/221#issuecomment-86609944 .

sbrunner commented 9 years ago

OK, thanks, actually it's not a issue :-)

sbrunner commented 9 years ago

I close it and reopen it I steal have an issue :-)