Instability with JDBCConfig and many layers / layer groups

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

Instability with JDBCConfig and many layers / layer groups

Damiano Albani-3
Hi,

I've been experiencing a strange instability issue lately with the JDBCConfig module in combination with lots of layers / layer groups in GeoServer.
As an end user, the behavior that I get is that GeoServer simply "freezes" quite randomly under load, not responding to requests for several minutes (be it WMS / WFS requests or even the admin interface).
I've tracked down this behavior due to some kind of database contention: the database connection pool gets somehow exhausted and GeoServer only returns to a working condition once the database connections time out.

For example, this is the kind of information shown in the HikariCP logs about the contention:
06 Feb 10:25:41 DEBUG [pool.HikariPool] - HikariPool-2 - Before cleanup stats (total=10, active=10, idle=0, waiting=10)
06 Feb 10:25:41 DEBUG [pool.HikariPool] - HikariPool-2 - After cleanup  stats (total=10, active=10, idle=0, waiting=10)
 
GeoServer is more or less frozen at this point, even though there is no CPU or database activity (current JDBCConfig-related connections are considered "idle" if I look in a tool like PgAdmin).

For reference, "HikariPool-2" is here the connection pool defined in my Tomcat configuration with:
<Resource name="jdbc/jdbcconfig"
          auth="Container"
          type="javax.sql.DataSource"
          factory="com.zaxxer.hikari.HikariJNDIFactory"
          driverClassName="org.postgresql.Driver"
          jdbcUrl="jdbc:postgresql://..."
          username="geoserverconfig"
          password="..."
          closeMethod="close"
          minimumIdle="2" maximumPoolSize="10" connectionTimeout="300000" maxLifetime="1800000" />

Activating the leak detection functionality in HikariCP produces the following:
java.lang.Exception: Apparent connection leak detected
  at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
  at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
  at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:619)
  at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:684)
  at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:711)
  at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:761)
  at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:211)
  at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:219)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1058)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1043)
  at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4739)
  at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3524)
  at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2317)
  at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2280)
  at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2195)
  at com.google.common.cache.LocalCache.get(LocalCache.java:3934)
  at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4736)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase.getById(ConfigDatabase.java:898)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase$2.apply(ConfigDatabase.java:329)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase$2.apply(ConfigDatabase.java:325)
  at com.google.common.collect.Lists$TransformingRandomAccessList$1.transform(Lists.java:582)
  at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48)
  at com.google.common.collect.Iterators$7.computeNext(Iterators.java:646)
  at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143)
  at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138)
  at org.geoserver.catalog.util.CloseableIteratorAdapter.hasNext(CloseableIteratorAdapter.java:45)
  at org.geoserver.jdbcconfig.catalog.JDBCCatalogFacade.findUnique(JDBCCatalogFacade.java:819)
  at org.geoserver.jdbcconfig.catalog.JDBCCatalogFacade.getLayerGroupByName(JDBCCatalogFacade.java:702)
  at org.geoserver.catalog.impl.CatalogImpl.getLayerGroupByName(CatalogImpl.java:1085)
  at org.geoserver.catalog.impl.CatalogImpl.getLayerGroupByName(CatalogImpl.java:1075)
  at org.geoserver.security.SecureCatalogImpl.getLayerGroupByName(SecureCatalogImpl.java:337)
  at org.geoserver.catalog.impl.AbstractFilteredCatalog.getLayerGroupByName(AbstractFilteredCatalog.java:229)
  at org.geoserver.catalog.impl.AbstractCatalogDecorator.getLayerGroupByName(AbstractCatalogDecorator.java:468)
  at org.geoserver.catalog.impl.LocalWorkspaceCatalog.getLayerGroupByName(LocalWorkspaceCatalog.java:175)
  at org.geoserver.wms.WMSWorkspaceQualifier.qualifyLayerNames(WMSWorkspaceQualifier.java:81)
  at org.geoserver.wms.WMSWorkspaceQualifier.qualifyLayerNamesKVP(WMSWorkspaceQualifier.java:66)
  at org.geoserver.wms.WMSWorkspaceQualifier.qualifyRequest(WMSWorkspaceQualifier.java:30)
  at org.geoserver.ows.WorkspaceQualifyingCallback.serviceDispatched(WorkspaceQualifyingCallback.java:42)
  at org.geoserver.ows.Dispatcher.fireServiceDispatchedCallback(Dispatcher.java:572)
  at org.geoserver.ows.Dispatcher.service(Dispatcher.java:567)
  at org.geoserver.ows.Dispatcher.handleRequestInternal(Dispatcher.java:238)
  at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:174)
  at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:50)
  at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:963)
  at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897)
  at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
  at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:634)
  at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
  at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
  at org.geoserver.filters.ThreadLocalsCleanupFilter.doFilter(ThreadLocalsCleanupFilter.java:26)

In addition to HikariCP, I've tried with Apache DBCP 2 and C3P0 as well. In all cases the behavior stays consistent with what I described above.
Given that I never had any such issue with layers in the past, I have the feeling that the problem related to (large?) layer groups, as shown in the stack trace. But I could be wrong of course.

I have tested with the latest stable versions from the 2.12 and 2.14 branch and I got similar results.
Has anyone seen that before? How could I further debug the database contention issue (e.g. by being sure that connections are correctly closed by example).

Thanks.


_______________________________________________
Geoserver-users mailing list

Please make sure you read the following two resources before posting to this list:
- Earning your support instead of buying it, but Ian Turton: http://www.ianturton.com/talks/foss4g.html#/
- The GeoServer user list posting guidelines: http://geoserver.org/comm/userlist-guidelines.html

If you want to request a feature or an improvement, also see this: https://github.com/geoserver/geoserver/wiki/Successfully-requesting-and-integrating-new-features-and-improvements-in-GeoServer


[hidden email]
https://lists.sourceforge.net/lists/listinfo/geoserver-users
Reply | Threaded
Open this post in threaded view
|

Re: Instability with JDBCConfig and many layers / layer groups

Niels Charlier

Hello Damiano,

I have not come across this issue, but we don't use layer groups which could confirm your suspicion that is somewhat related to that. However, I have no idea how that is possible because layer group are not particularly treated differently.

I don't see any reason to believe there is a connection leak. For some reason it must be opening too many connections at once.

Is there any chance you could provide a dataset that reproduces the issue?

Kind Regards

Niels

On 14/02/2019 16:13, Damiano Albani wrote:
Hi,

I've been experiencing a strange instability issue lately with the JDBCConfig module in combination with lots of layers / layer groups in GeoServer.
As an end user, the behavior that I get is that GeoServer simply "freezes" quite randomly under load, not responding to requests for several minutes (be it WMS / WFS requests or even the admin interface).
I've tracked down this behavior due to some kind of database contention: the database connection pool gets somehow exhausted and GeoServer only returns to a working condition once the database connections time out.

For example, this is the kind of information shown in the HikariCP logs about the contention:
06 Feb 10:25:41 DEBUG [pool.HikariPool] - HikariPool-2 - Before cleanup stats (total=10, active=10, idle=0, waiting=10)
06 Feb 10:25:41 DEBUG [pool.HikariPool] - HikariPool-2 - After cleanup  stats (total=10, active=10, idle=0, waiting=10)
 
GeoServer is more or less frozen at this point, even though there is no CPU or database activity (current JDBCConfig-related connections are considered "idle" if I look in a tool like PgAdmin).

For reference, "HikariPool-2" is here the connection pool defined in my Tomcat configuration with:
<Resource name="jdbc/jdbcconfig"
          auth="Container"
          type="javax.sql.DataSource"
          factory="com.zaxxer.hikari.HikariJNDIFactory"
          driverClassName="org.postgresql.Driver"
          jdbcUrl="jdbc:postgresql://..."
          username="geoserverconfig"
          password="..."
          closeMethod="close"
          minimumIdle="2" maximumPoolSize="10" connectionTimeout="300000" maxLifetime="1800000" />

Activating the leak detection functionality in HikariCP produces the following:
java.lang.Exception: Apparent connection leak detected
  at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
  at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
  at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
  at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:619)
  at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:684)
  at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:711)
  at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:761)
  at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:211)
  at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:219)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1058)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1043)
  at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4739)
  at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3524)
  at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2317)
  at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2280)
  at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2195)
  at com.google.common.cache.LocalCache.get(LocalCache.java:3934)
  at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4736)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase.getById(ConfigDatabase.java:898)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase$2.apply(ConfigDatabase.java:329)
  at org.geoserver.jdbcconfig.internal.ConfigDatabase$2.apply(ConfigDatabase.java:325)
  at com.google.common.collect.Lists$TransformingRandomAccessList$1.transform(Lists.java:582)
  at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48)
  at com.google.common.collect.Iterators$7.computeNext(Iterators.java:646)
  at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143)
  at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138)
  at org.geoserver.catalog.util.CloseableIteratorAdapter.hasNext(CloseableIteratorAdapter.java:45)
  at org.geoserver.jdbcconfig.catalog.JDBCCatalogFacade.findUnique(JDBCCatalogFacade.java:819)
  at org.geoserver.jdbcconfig.catalog.JDBCCatalogFacade.getLayerGroupByName(JDBCCatalogFacade.java:702)
  at org.geoserver.catalog.impl.CatalogImpl.getLayerGroupByName(CatalogImpl.java:1085)
  at org.geoserver.catalog.impl.CatalogImpl.getLayerGroupByName(CatalogImpl.java:1075)
  at org.geoserver.security.SecureCatalogImpl.getLayerGroupByName(SecureCatalogImpl.java:337)
  at org.geoserver.catalog.impl.AbstractFilteredCatalog.getLayerGroupByName(AbstractFilteredCatalog.java:229)
  at org.geoserver.catalog.impl.AbstractCatalogDecorator.getLayerGroupByName(AbstractCatalogDecorator.java:468)
  at org.geoserver.catalog.impl.LocalWorkspaceCatalog.getLayerGroupByName(LocalWorkspaceCatalog.java:175)
  at org.geoserver.wms.WMSWorkspaceQualifier.qualifyLayerNames(WMSWorkspaceQualifier.java:81)
  at org.geoserver.wms.WMSWorkspaceQualifier.qualifyLayerNamesKVP(WMSWorkspaceQualifier.java:66)
  at org.geoserver.wms.WMSWorkspaceQualifier.qualifyRequest(WMSWorkspaceQualifier.java:30)
  at org.geoserver.ows.WorkspaceQualifyingCallback.serviceDispatched(WorkspaceQualifyingCallback.java:42)
  at org.geoserver.ows.Dispatcher.fireServiceDispatchedCallback(Dispatcher.java:572)
  at org.geoserver.ows.Dispatcher.service(Dispatcher.java:567)
  at org.geoserver.ows.Dispatcher.handleRequestInternal(Dispatcher.java:238)
  at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:174)
  at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:50)
  at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:963)
  at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897)
  at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
  at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:634)
  at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
  at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
  at org.geoserver.filters.ThreadLocalsCleanupFilter.doFilter(ThreadLocalsCleanupFilter.java:26)

In addition to HikariCP, I've tried with Apache DBCP 2 and C3P0 as well. In all cases the behavior stays consistent with what I described above.
Given that I never had any such issue with layers in the past, I have the feeling that the problem related to (large?) layer groups, as shown in the stack trace. But I could be wrong of course.

I have tested with the latest stable versions from the 2.12 and 2.14 branch and I got similar results.
Has anyone seen that before? How could I further debug the database contention issue (e.g. by being sure that connections are correctly closed by example).

Thanks.


_______________________________________________
Geoserver-users mailing list

Please make sure you read the following two resources before posting to this list:
- Earning your support instead of buying it, but Ian Turton: http://www.ianturton.com/talks/foss4g.html#/
- The GeoServer user list posting guidelines: http://geoserver.org/comm/userlist-guidelines.html

If you want to request a feature or an improvement, also see this: https://github.com/geoserver/geoserver/wiki/Successfully-requesting-and-integrating-new-features-and-improvements-in-GeoServer


[hidden email]
https://lists.sourceforge.net/lists/listinfo/geoserver-users


_______________________________________________
Geoserver-users mailing list

Please make sure you read the following two resources before posting to this list:
- Earning your support instead of buying it, but Ian Turton: http://www.ianturton.com/talks/foss4g.html#/
- The GeoServer user list posting guidelines: http://geoserver.org/comm/userlist-guidelines.html

If you want to request a feature or an improvement, also see this: https://github.com/geoserver/geoserver/wiki/Successfully-requesting-and-integrating-new-features-and-improvements-in-GeoServer


[hidden email]
https://lists.sourceforge.net/lists/listinfo/geoserver-users