Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HTTP connections are not returned to the pool in GWC and it blocks subsequent requests.. #1308

Open
vitalus opened this issue Aug 17, 2024 · 6 comments

Comments

@vitalus
Copy link

vitalus commented Aug 17, 2024

GeoServer closes WMS service API with HTTP Basic authentication.

GWC sends internal request to WMS without credentials (if they are not configured) and also is not able to authenticate against WMS service..

WMSHttpHelper.connectAndCheckHeaders throws Service Exception (because WMS service responds with 401):

	        if (responseCode != 200 && responseCode != 204) {
	            tileRespRecv.setError();
	            throw new ServiceException(
	                    "Unexpected response code from backend: "
	                            + responseCode
	                            + " for "
	                            + wmsBackendUrl.toString());
	        }

So, in this workflow an allocated (from the pool) HTTP connection is never released back to the pool.
By default 2 connections are per HTTP route (is is also questionable, shouldn't we allow more for internal GWC-WMS communication?)

So, connections are taken from the pool and never returned. All subsequent connections will wait pool without timeout.. (timeone is alos needed for internal connections).

AN easy fix is to put all content of connectAndCheckHeaders into try{}finally{}:

Something like this (tried quickly and locking problem is gone at least, regardless workflow connection is returned to the pool):

image

@aaime
Copy link
Member

aaime commented Aug 18, 2024

When you say "internal", are you talking about the GWC running inside GeoServer?
If so, you're reporting on the wrong repository (no GWC code is involved), and there is no actual HTTP request involved, it's using a fake HTTP request:
https://github.com/geoserver/geoserver/blob/main/src/gwc/src/main/java/org/geoserver/gwc/GWC.java#L1361

What you're pointing to seems to be the HTTP client used by the WMS Layers in a stand-alone GWC instead. Please make sure it's the last time you post a screenshot of code in a report, link to the actual code in the repository instead.

@vitalus
Copy link
Author

vitalus commented Aug 18, 2024

GWC runs inside GeoServer (embedded) but works in usual way with just normal HTTP request.

So, the scenario is fully applicable also to standalone GWC.


"qtp1373072083-29" #29 prio=5 os_prio=0 cpu=2640.62ms elapsed=87.00s tid=0x00000260fa091d10 nid=15076 waiting on condition  [0x000000a533bfa000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
        - parking to wait for  <0x000000041af15ae8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:341)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block([email protected]/AbstractQueuedSynchronizer.java:506)
        at java.util.concurrent.ForkJoinPool.unmanagedBlock([email protected]/ForkJoinPool.java:3464)
        at java.util.concurrent.ForkJoinPool.managedBlock([email protected]/ForkJoinPool.java:3435)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await([email protected]/AbstractQueuedSynchronizer.java:1623)
        at org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:391)
        at org.apache.http.pool.AbstractConnPool.access$300(AbstractConnPool.java:70)
        at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:253)
        - locked <0x000000043221b438> (a org.apache.http.pool.AbstractConnPool$2)
        at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:198)
        at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:306)
        at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:282)
        at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)
        at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
        at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
        at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
        at org.geowebcache.layer.wms.WMSHttpHelper.executeRequest(WMSHttpHelper.java:361)
        at org.geowebcache.layer.wms.WMSHttpHelper.connectAndCheckHeaders(WMSHttpHelper.java:179)
        at org.geowebcache.layer.wms.WMSHttpHelper.makeRequest(WMSHttpHelper.java:127)
        at org.geowebcache.layer.wms.WMSSourceHelper.makeRequest(WMSSourceHelper.java:53)
        at org.geowebcache.layer.wms.WMSLayer.getMetatilingReponse(WMSLayer.java:372)
        at org.geowebcache.layer.wms.WMSLayer.getTile(WMSLayer.java:283)
        at org.geowebcache.util.ResponseUtils.writeTile(ResponseUtils.java:101)
        at org.geowebcache.GeoWebCacheDispatcher.handleServiceRequest(GeoWebCacheDispatcher.java:436)
        at org.geowebcache.GeoWebCacheDispatcher.handleRequestInternal(GeoWebCacheDispatcher.java:288)
        at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:177)
        at org.geoserver.gwc.dispatch.GwcServiceProxy.dispatch(GwcServiceProxy.java:87)
        at java.lang.invoke.LambdaForm$DMH/0x000000080103c000.invokeVirtual([email protected]/LambdaForm$DMH)
        at java.lang.invoke.LambdaForm$MH/0x0000000801aea400.invoke([email protected]/LambdaForm$MH)
        at java.lang.invoke.LambdaForm$MH/0x0000000800c05400.invokeExact_MT([email protected]/LambdaForm$MH)
        at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl([email protected]/DirectMethodHandleAccessor.java:156)
        at jdk.internal.reflect.DirectMethodHandleAccessor.invoke([email protected]/DirectMethodHandleAccessor.java:104)
        at java.lang.reflect.Method.invoke([email protected]/Method.java:577)
        at org.geoserver.ows.Dispatcher.execute(Dispatcher.java:905)
        at org.geoserver.ows.Dispatcher.handleRequestInternal(Dispatcher.java:269)
        at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:177)
        at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:51)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1072)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:965)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
        at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:503)
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:590)
        at org.eclipse.jetty.ee8.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1151)
        at org.eclipse.jetty.ee8.servlet.ServletHolder.handle(ServletHolder.java:640)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1374)
        at org.geoserver.filters.ThreadLocalsCleanupFilter.doFilter(ThreadLocalsCleanupFilter.java:28)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:171)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
        at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:73)
        at org.geoserver.ows.HTTPHeadersCollector.doFilter(HTTPHeadersCollector.java:48)
        at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:70)
        at org.geoserver.filters.HTTPMethodFilter.doFilter(HTTPMethodFilter.java:36)
        at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:70)
        at org.geoserver.filters.LoggingFilter.doFilter(LoggingFilter.java:194)
        at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:70)
        at org.geoserver.filters.SpringDelegatingFilter.doFilter(SpringDelegatingFilter.java:43)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:171)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
        at org.geoserver.platform.AdvancedDispatchFilter.doFilter(AdvancedDispatchFilter.java:39)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:171)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:352)
        at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:71)
        at org.springframework.security.web.access.intercept.AuthorizationFilter.doFilter(AuthorizationFilter.java:100)
        at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:75)
        at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:92)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:71)
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:126)
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:120)
        at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:75)
        at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:92)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.geoserver.security.filter.GeoServerPreAuthenticationFilter.doFilter(GeoServerPreAuthenticationFilter.java:72)
        at org.geoserver.security.jwtheaders.filter.GeoServerJwtHeadersFilter.doFilter(GeoServerJwtHeadersFilter.java:145)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:71)
        at org.geoserver.security.filter.GeoServerSecurityContextPersistenceFilter$1.doFilterInternal(GeoServerSecurityContextPersistenceFilter.java:74)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:75)
        at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:92)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:225)
        at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:190)
        at org.geoserver.security.GeoServerSecurityFilterChainProxy.doFilter(GeoServerSecurityFilterChainProxy.java:141)
        at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:354)
        at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:171)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
        at org.geoserver.filters.XFrameOptionsFilter.doFilter(XFrameOptionsFilter.java:116)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:171)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
        at org.geoserver.filters.GZIPFilter.doFilter(GZIPFilter.java:48)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:171)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
        at org.geoserver.filters.SessionDebugFilter.doFilter(SessionDebugFilter.java:49)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:171)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
        at org.geoserver.filters.FlushSafeFilter.doFilter(FlushSafeFilter.java:42)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:171)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
        at org.eclipse.jetty.ee8.servlets.CrossOriginFilter.handle(CrossOriginFilter.java:302)
        at org.eclipse.jetty.ee8.servlets.CrossOriginFilter.doFilter(CrossOriginFilter.java:270)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:171)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
        at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        at org.eclipse.jetty.ee8.servlet.FilterHolder.doFilter(FilterHolder.java:177)
        at org.eclipse.jetty.ee8.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1348)
  .........

As written above, in case of ServiceException there is no reading attempt from input stream of response and normally working connection releasing code is omitted. Both 2 connections (that by default are allowed per route in HttpComponents) are leased and never returned to the pool, then all other subsequent requests are endlessly waiting...

Also if you check who calls GWC.dispatchOwsRequest - it seems only getFeatureInfo type of request. So, no "fake HTTP requests" for normal getMap of WMS from GWC to WMS..

I am not reporting to the wrong repo. Problem is debugged, dirty fix is applied myself (a simple one), but I would like , may be maintainers analyze the case and prefer to fix it by doing a bigger refactoring..

@aaime
Copy link
Member

aaime commented Aug 18, 2024

How in the world have you configured the GWC? It seems like you have setup a WMSLayer manually in gwc.xml rather than simply enabling tile caching in the GeoServer layer configuration, hence the usage of WMSLayer. A normal setup (tile caching tab in the GeoServer layer page) for embedded GWC would have make it use a GeoServerTileLayer instead.

Here is what the stack trace looks like in that case:

"qtp681639276-49" prio=5 Id=49 RUNNABLE (suspended)
	at org.geoserver.wms.GetMap.run(GetMap.java:108)
	at org.geoserver.wms.DefaultWebMapService.getMap(DefaultWebMapService.java:250)
	at java.lang.invoke.LambdaForm$DMH/0x0000707c8423a000.invokeInterface(
	at java.lang.invoke.LambdaForm$MH/0x0000707c842f0400.invoke(
	at java.lang.invoke.Invokers$Holder.invokeExact_MT(
	at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(DirectMethodHandleAccessor.java:154)
	at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.lang.reflect.Method.invoke(Method.java:580)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
	at org.geoserver.kml.WebMapServiceKmlInterceptor.invoke(WebMapServiceKmlInterceptor.java:38)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.geoserver.gwc.wms.CacheSeedingWebMapService.invoke(CacheSeedingWebMapService.java:57)
	at org.geoserver.gwc.wms.CacheSeedingWebMapService.invoke(CacheSeedingWebMapService.java:32)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.geoserver.gwc.wms.CachingWebMapService.invoke(CachingWebMapService.java:74)
	at org.geoserver.gwc.wms.CachingWebMapService.invoke(CachingWebMapService.java:43)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.geoserver.ows.util.RequestObjectLogger.invoke(RequestObjectLogger.java:29)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:241)
	at jdk.proxy3.$Proxy91.getMap(
	at java.lang.invoke.DirectMethodHandle$Holder.invokeSpecial(
	at java.lang.invoke.LambdaForm$MH/0x0000707c842f0400.invoke(
	at java.lang.invoke.Invokers$Holder.invokeExact_MT(
	at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(DirectMethodHandleAccessor.java:154)
	at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.lang.reflect.Method.invoke(Method.java:580)
	at org.geoserver.ows.Dispatcher.execute(Dispatcher.java:905)
	at org.geoserver.ows.Dispatcher.handleRequestInternal(Dispatcher.java:269)
	at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:177)
	at org.geoserver.gwc.GWC.dispatchOwsRequest(GWC.java:1368)
	at org.geoserver.gwc.layer.GeoServerTileLayer.dispatchGetMap(GeoServerTileLayer.java:693)
	at org.geoserver.gwc.layer.GeoServerTileLayer.getMetatilingReponse(GeoServerTileLayer.java:613)
	at org.geoserver.gwc.layer.GeoServerTileLayer.getTile(GeoServerTileLayer.java:558)
	at org.geowebcache.util.ResponseUtils.writeTile(ResponseUtils.java:101)
	at org.geowebcache.GeoWebCacheDispatcher.handleServiceRequest(GeoWebCacheDispatcher.java:428)
	at org.geowebcache.GeoWebCacheDispatcher.handleRequestInternal(GeoWebCacheDispatcher.java:288)
	at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:177)
	at org.geoserver.gwc.dispatch.GwcServiceProxy.dispatch(GwcServiceProxy.java:87)
	at java.lang.invoke.LambdaForm$DMH/0x0000707c847a8000.invokeVirtual(
	at java.lang.invoke.LambdaForm$MH/0x0000707c84560c00.invoke(
	at java.lang.invoke.LambdaForm$MH/0x0000707c84002800.invokeExact_MT(
	at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(DirectMethodHandleAccessor.java:155)
	at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.lang.reflect.Method.invoke(Method.java:580)
	at org.geoserver.ows.Dispatcher.execute(Dispatcher.java:905)
	at org.geoserver.ows.Dispatcher.handleRequestInternal(Dispatcher.java:269)

Using a HTTP connection for GeoServer to talk to itself was the first thing the developers integrating GWC with Geoserver tried to avoid, some 15-ish years ago.

@vitalus
Copy link
Author

vitalus commented Aug 18, 2024

Answer: Using geowebcache.xml manual configuration within GeoServer.

But it is not related to the problem in general, because there is a standalone mode and behavior will be the same: deadlocking of all subsequent connections to GWC waiting a connection from pool where previous requests (failed with 401 from GeoServer) did not release connections..

@vitalus
Copy link
Author

vitalus commented Aug 18, 2024

Standalone GWC is a production option, let's say (for me) in dev.env environment it's easier to test everything using GWC embedded. So , it allows creation of geowebcache.xml manually with all necessary tweaks in dev.env with GWC embedded (running as GeoServer from Eclipse in debug) and then use it for prod where GWC is standalone.

@vitalus
Copy link
Author

vitalus commented Aug 18, 2024

#1194 is about the same problem. Reported in 2023.

It's critical defect with an easy fix in WMSHttpHelper ... (just dirty fix with the following general code improvement if necessary):


    private void connectAndCheckHeaders(
            TileResponseReceiver tileRespRecv,
            URL wmsBackendUrl,
            Map<String, String> wmsParams,
            MimeType requestMimeType,
            Integer backendTimeout,
            Resource target,
            WMSLayer.HttpRequestMode httpRequestMode)
            throws GeoWebCacheException {
....

        try{

...
        }finally {
        	
        	//Guarantees that connections are released to the pool
        	if(method != null && method instanceof CloseableHttpResponse) {
        		try {
					((CloseableHttpResponse)method).close();
				} catch (IOException e) {
					e.printStackTrace();
				}
        	}
        }
}

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

No branches or pull requests

2 participants