GeoWebCache / geowebcache

GeoWebCache is a tile caching server implemented in Java that provides various tile caching services like WMS-C, TMS, WMTS, Google Maps, MS Bing and more
https://www.geowebcache.org
343 stars 280 forks source link

Disk quota JDBC throwing deadlock errors #464

Open emilzse opened 7 years ago

emilzse commented 7 years ago

We have configured quota store as JDBC into PostgreSQL database.

When there is some load we are experiencing that it is throwing deadlock errors (also on single node).

Is there anyone else having this issues?

I have found this in code that i guess was supposed to handle this issue:

// sort the payloads by page id as a deadlock avoidance measure, out
// of order updates may result in deadlock with the addHitsAndSetAccessTime method
List<PageStatsPayload> sorted = sortPayloads(statsUpdates);

See stacktrace below:

2016-12-20 11:47:06,789 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] org.geowebcache.diskquota.jdbc.ParametricDataAccessException: Failed to execute statement INSERT INTO gwc.TILEPAGE SELECT :key, :tileSetId, :pageZ, :pageX, :pageY, :creationTime, :frequencyOfUse, :lastAccessTime, :fillFactor, :numHits WHERE NOT EXISTS(SELECT 1 FROM gwc.TILEPAGE WHERE KEY = :key) with params: {numHits=0, lastAccessTime=24616067, creationTime=24616067, tileSetId=layer_xxx#EPSG:4326#image/png, frequencyOfUse=0.0, pageZ=6, pageY=2, key=layer_xxx#EPSG:4326#image/png@6,2,6, pageX=6, fillFactor=1.0}; nested exception is org.springframework.dao.DeadlockLoserDataAccessException: PreparedStatementCallback; SQL [INSERT INTO gwc.TILEPAGE SELECT ?, ?, ?, ?, ?, ?, ?, ?, ?, ? WHERE NOT EXISTS(SELECT 1 FROM gwc.TILEPAGE WHERE KEY = ?)]; ERROR: deadlock detected Detail: Process 14399 waits for ShareLock on transaction 237467563; blocked by process 14398. Process 14398 waits for ShareLock on transaction 237467562; blocked by process 14399. Hint: See server log for query details.; nested exception is org.postgresql.util.PSQLException: ERROR: deadlock detected Detail: Process 14399 waits for ShareLock on transaction 237467563; blocked by process 14398. Process 14398 waits for ShareLock on transaction 237467562; blocked by process 14399. Hint: See server log for query details. 2016-12-20 11:47:06,790 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.jdbc.SimpleJdbcTemplate.update(SimpleJdbcTemplate.java:70) 2016-12-20 11:47:06,791 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.jdbc.JDBCQuotaStore.createNewPageStats(JDBCQuotaStore.java:608) 2016-12-20 11:47:06,792 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.jdbc.JDBCQuotaStore.access$400(JDBCQuotaStore.java:69) 2016-12-20 11:47:06,794 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.jdbc.JDBCQuotaStore$9.upsertTilePageFillFactor(JDBCQuotaStore.java:522) 2016-12-20 11:47:06,797 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.jdbc.JDBCQuotaStore$9.doInTransactionWithoutResult(JDBCQuotaStore.java:463) 2016-12-20 11:47:06,800 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.springframework.transaction.support.TransactionCallbackWithoutResult.doInTransaction(TransactionCallbackWithoutResult.java:34) 2016-12-20 11:47:06,805 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:133) 2016-12-20 11:47:06,808 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.jdbc.JDBCQuotaStore.addToQuotaAndTileCounts(JDBCQuotaStore.java:451) 2016-12-20 11:47:06,811 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.QueuedQuotaUpdatesConsumer.commit(QueuedQuotaUpdatesConsumer.java:312) 2016-12-20 11:47:06,811 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.QueuedQuotaUpdatesConsumer.checkAggregatedTimeout(QueuedQuotaUpdatesConsumer.java:293) 2016-12-20 11:47:06,897 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.QueuedQuotaUpdatesConsumer.checkAggregatedTimeouts(QueuedQuotaUpdatesConsumer.java:250) 2016-12-20 11:47:06,904 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.QueuedQuotaUpdatesConsumer.call(QueuedQuotaUpdatesConsumer.java:198) 2016-12-20 11:47:06,933 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at org.geowebcache.diskquota.QueuedQuotaUpdatesConsumer.call(QueuedQuotaUpdatesConsumer.java:23) 2016-12-20 11:47:06,940 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at java.util.concurrent.FutureTask.run(FutureTask.java:266) 2016-12-20 11:47:06,940 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 2016-12-20 11:47:06,948 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 2016-12-20 11:47:06,951 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] at java.lang.Thread.run(Thread.java:745) 2016-12-20 11:47:06,993 ERROR (GWC DiskQuota Updates Gathering Thread-2)[STDERR] Caused by: org.springframework.dao.DeadlockLoserDataAccessException: PreparedStatementCallback; SQL [INSERT INTO gwc.TILEPAGE SELECT ?, ?, ?, ?, ?, ?, ?, ?, ?, ? WHERE NOT EXISTS(SELECT 1 FROM gwc.TILEPAGE WHERE KEY = ?)]; ERROR: deadlock detected Detail: Process 14399 waits for ShareLock on transaction 237467563; blocked by process 14398. Process 14398 waits for ShareLock on transaction 237467562; blocked by process 14399. Hint: See server log for query details.; nested exception is org.postgresql.util.PSQLException: ERROR: deadlock detected Detail: Process 14399 waits for ShareLock on transaction 237467563; blocked by process 14398. Process 14398 waits for ShareLock on transaction 237467562; blocked by process 14399. Hint: See server log for query details.

aaime commented 7 years ago

See here: https://osgeo-org.atlassian.net/browse/GEOS-7018 Happened only once, never had the time to look into it.

emilzse commented 7 years ago

Thank you for reply. It seems to happen on regular basis in our production environment.

aaime commented 7 years ago

Looks like you have good incentive to fix it then ;-)

rajanski commented 6 years ago

We have similar behaviour when using the in-process db (the default setting for the disk quota db)

aaime commented 6 years ago

If a ticket is urgent for you and not moving, you can also check http://geoserver.org/comm/