The way JDBCConfig manages data loading and database connections is prone to deadlock.
First observation is based on legitimate catalog client code like this (from the WMS 1.3 capabilities translator):
try (CloseableIterator<LayerGroupInfo> lgIter =
catalog.list(LayerGroupInfo.class, lgFilter, null, null, lgOrder);
CloseableIterator<LayerInfo> iter =
catalog.list(LayerInfo.class, filter, null, null, order))
{ layerGroups = Lists.newArrayList(lgIter); layers = Lists.newArrayList(iter); }
A client can invoke as many “list” calls on the catalog as needed, as long as it closes the iterators. However, each iterator uses a connection from the JDBC connection pool. It follows that if enough GetCapabilities reach the server in parallel, they will lock down themselves, with each one holding the connection for the first iterator, but never able to get the second, due to the max size of the pool being reached.
The classic deadlock avoidance, grabbing all resources at the beginning, cannot be applied here, as Catalog client code can legitimalely open as many iterators as it wants.
A work around would be to load into an array list each iterator, but it’s just that, a work around, the deadlock can pop up in other areas as well.
The second case can be exemplified by this stack trace:
- waiting on <0x000000073f9e5a70> (a org.apache.commons.pool.impl.GenericObjectPool$Latch)
at java.lang.Object.wait(Object.java:502)
at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1104)
- locked <0x000000073f9e5a70> (a org.apache.commons.pool.impl.GenericObjectPool$Latch)
at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106)
at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:158)
at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:116)
at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:79)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:612)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:669)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:694)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:748)
at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:236)
at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:245)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1277)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1262)
at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4876)
at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3528)
at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2277)
at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2154)
- locked <0x000000073f9e4d58> (a com.google.common.cache.LocalCache$StrongAccessEntry)
at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2044)
at com.google.common.cache.LocalCache.get(LocalCache.java:3952)
at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4871)
at org.geoserver.jdbcconfig.internal.ConfigDatabase.getById(ConfigDatabase.java:1026)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$$FastClassBySpringCGLIB$$dd464281.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:685)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$$EnhancerBySpringCGLIB$$bf8f6c07.getById(<generated>)
at org.geoserver.jdbcconfig.catalog.JDBCCatalogFacade.getStore(JDBCCatalogFacade.java:112)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.geoserver.catalog.LockingCatalogFacade.invoke(LockingCatalogFacade.java:36)
at com.sun.proxy.$Proxy30.getStore(Unknown Source)
at org.geoserver.catalog.impl.CatalogImpl.getStore(CatalogImpl.java:254)
at org.geoserver.catalog.impl.ResolvingProxy.resolve(ResolvingProxy.java:81)
at org.geoserver.config.util.XStreamPersister$ReferenceConverter.unmarshal(XStreamPersister.java:1221)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshallField(AbstractReflectionConverter.java:499)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doUnmarshal(AbstractReflectionConverter.java:425)
at org.geoserver.config.util.XStreamPersister$ResourceInfoConverter.doUnmarshal(XStreamPersister.java:1930)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshal(AbstractReflectionConverter.java:277)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)
at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:134)
at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32)
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1487)
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1467)
at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1347)
at org.geoserver.config.util.XStreamPersister.load(XStreamPersister.java:664)
at org.geoserver.jdbcconfig.internal.XStreamInfoSerialBinding.entryToObject(XStreamInfoSerialBinding.java:37)
at org.geoserver.jdbcconfig.internal.InfoRowMapper.mapRow(InfoRowMapper.java:54)
at org.geoserver.jdbcconfig.internal.InfoRowMapper.mapRow(InfoRowMapper.java:17)
at org.springframework.jdbc.core.RowMapperResultSetExtractor.extractData(RowMapperResultSetExtractor.java:94)
at org.springframework.jdbc.core.RowMapperResultSetExtractor.extractData(RowMapperResultSetExtractor.java:61)
at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:679)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:617)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:669)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:694)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:748)
at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:236)
at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:245)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1277)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1262)
at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4876)
at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3528)
at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2277)
at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2154)
- locked <0x000000073ea4c468> (a com.google.common.cache.LocalCache$StrongAccessEntry)
at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2044)
at com.google.common.cache.LocalCache.get(LocalCache.java:3952)
at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4871)
at org.geoserver.jdbcconfig.internal.ConfigDatabase.getById(ConfigDatabase.java:1026)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$$FastClassBySpringCGLIB$$dd464281.invoke(<generated>)
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:685)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$$EnhancerBySpringCGLIB$$bf8f6c07.getById(<generated>)
at org.geoserver.jdbcconfig.catalog.JDBCCatalogFacade.getResource(JDBCCatalogFacade.java:220)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.geoserver.catalog.LockingCatalogFacade.invoke(LockingCatalogFacade.java:36)
at com.sun.proxy.$Proxy30.getResource(Unknown Source)
at org.geoserver.catalog.impl.CatalogImpl.getResource(CatalogImpl.java:478)
at org.geoserver.catalog.impl.ResolvingProxy.resolve(ResolvingProxy.java:113)
at org.geoserver.config.util.XStreamPersister$ReferenceConverter.unmarshal(XStreamPersister.java:1221)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshallField(AbstractReflectionConverter.java:499)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.doUnmarshal(AbstractReflectionConverter.java:425)
at org.geoserver.config.util.XStreamPersister$LayerInfoConverter.doUnmarshal(XStreamPersister.java:2031)
at com.thoughtworks.xstream.converters.reflection.AbstractReflectionConverter.unmarshal(AbstractReflectionConverter.java:277)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)
at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)
at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:134)
at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32)
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1487)
at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1467)
at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1347)
at org.geoserver.config.util.XStreamPersister.load(XStreamPersister.java:664)
at org.geoserver.jdbcconfig.internal.XStreamInfoSerialBinding.entryToObject(XStreamInfoSerialBinding.java:37)
at org.geoserver.jdbcconfig.internal.InfoRowMapper.mapRow(InfoRowMapper.java:54)
at org.geoserver.jdbcconfig.internal.InfoRowMapper.mapRow(InfoRowMapper.java:17)
at org.springframework.jdbc.core.RowMapperResultSetExtractor.extractData(RowMapperResultSetExtractor.java:94)
at org.springframework.jdbc.core.RowMapperResultSetExtractor.extractData(RowMapperResultSetExtractor.java:61)
at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:679)
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:617)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:669)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:694)
at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:748)
at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:236)
at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForObject(NamedParameterJdbcTemplate.java:245)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1277)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$CatalogLoader.call(ConfigDatabase.java:1262)
at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4876)
at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3528)
at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2277)
at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2154)
- locked <0x000000073e986bc0> (a com.google.common.cache.LocalCache$StrongAccessEntry)
at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2044)
at com.google.common.cache.LocalCache.get(LocalCache.java:3952)
at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4871)
at org.geoserver.jdbcconfig.internal.ConfigDatabase.getById(ConfigDatabase.java:1026)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$2.apply(ConfigDatabase.java:393)
at org.geoserver.jdbcconfig.internal.ConfigDatabase$2.apply(ConfigDatabase.java:389)
at com.google.common.collect.Lists$TransformingRandomAccessList$1.transform(Lists.java:616)
at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)
at com.google.common.collect.Iterators$5.computeNext(Iterators.java:638)
at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
at com.google.common.collect.Iterators$5.computeNext(Iterators.java:637)
at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
at org.geoserver.catalog.util.CloseableIteratorAdapter.hasNext(CloseableIteratorAdapter.java:46)
at com.google.common.collect.TransformedIterator.hasNext(TransformedIterator.java:42)
at org.geoserver.catalog.util.CloseableIteratorAdapter.hasNext(CloseableIteratorAdapter.java:46)
at com.google.common.collect.Iterators$5.computeNext(Iterators.java:637)
at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
at org.geoserver.catalog.util.CloseableIteratorAdapter.hasNext(CloseableIteratorAdapter.java:46)
at com.google.common.collect.TransformedIterator.hasNext(TransformedIterator.java:42)
at org.geoserver.catalog.util.CloseableIteratorAdapter.hasNext(CloseableIteratorAdapter.java:46)
at org.geoserver.catalog.impl.LocalWorkspaceCatalog.list(LocalWorkspaceCatalog.java:535)
at org.geoserver.wms.capabilities.Capabilities_1_3_0_Transformer$Capabilities_1_3_0_Translator.handleLayers(Capabilities_1_3_0_Transformer.java:699)
This single list call is using, at the time the trace was taken, 4 different connections. This is how it gets there:
- The first connection is grabbed and used to get a list of the objects matching the filter
- The code gets a catalog object id for the first entry, and tries to resolve it against the cache
- The cache does not have it, and calls ConfigDatabase$CatalogLoader, which uses a JDCBTemplate, which in turns needs a connection.
- Reading the XML for the layer, causes XStream to figure out another object (the resource) is neeed, which triggers another lookup in the cache
- The lookup fails, and this causes another catalog loader call, with a different id, which uses JDBCTemplate (while the previous is still running), grabbing another connection. Reading the XML again, XStream figures out the reference to the store is missing, and tries to grab it from the cache… this ends up grabbing another connection
Both cases can be solved with an observation: the issue stems from the request using more than one connection, when one would do. In fact, it’s possible to create and keep open as many statements and result sets as needed, as long as they are used by a single thread. This is done automatically by Spring when the request is bound to a JTA transaction, but in this case, there is none, so a new connection is grabbed for each new JDBCTemplate.execute call.
I’ve found no way to share the connection per request without using transactions. A simple approach would be to open the connection and hold it till the end of the request, but it’s highly problematic, for example, a GetMap can run for tens of seconds, but needs catalog access only at the beginning.
We might need to do a per request connection sharing mechanism that is per request, but that releases the connection back to the pool as soon as the last user of it is done (when the reference counts are zero, release, if more usages are needed, just grab back from the pool, but never grab more than one connection at the same time).
|