search

gchq / stroom

Stroom is a highly scalable data storage, processing and analysis platform.
https://gchq.github.io/stroom-docs/
Apache License 2.0
431 stars 55 forks source link

SQL Deadlock v7.3-beta.19 #4221

Closed stroomdev10 closed 5 months ago

stroomdev10 commented 5 months ago 
SQL [insert into `index_field` (`fk_index_field_source_id`, `type`, `name`, `analyzer`, `indexed`, `stored`, `term_positions`, `case_sensitive`) values (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?) on duplicate key update `index_field`.`fk_index_field_source_id` = ?]; Deadlock found when trying to get lock; try restarting transaction 
org.jooq.exception.DataAccessException: SQL [insert into `index_field` (`fk_index_field_source_id`, `type`, `name`, `analyzer`, `indexed`, `stored`, `term_positions`, `case_sensitive`) values (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?), (?, ?, ?, ?, ?, ?, ?, ?) on duplicate key update `index_field`.`fk_index_field_source_id` = ?]; Deadlock found when trying to get lock; try restarting transaction
    at org.jooq_3.18.7.MYSQL.debug(Unknown Source)
    at org.jooq.impl.Tools.translate(Tools.java:3470)
    at org.jooq.impl.Tools.translate(Tools.java:3458)
    at org.jooq.impl.DefaultExecuteContext.sqlException(DefaultExecuteContext.java:802)
    at org.jooq.impl.AbstractQuery.execute(AbstractQuery.java:360)
    at org.jooq.impl.AbstractDelegatingQuery.execute(AbstractDelegatingQuery.java:115)
    at stroom.index.impl.db.IndexFieldDaoImpl.lambda$addFields$3(IndexFieldDaoImpl.java:133)
    at stroom.db.util.JooqUtil.lambda$transaction$2(JooqUtil.java:287)
    at org.jooq.impl.DefaultDSLContext.lambda$transaction$5(DefaultDSLContext.java:593)
    at org.jooq.impl.DefaultDSLContext.lambda$transactionResult0$3(DefaultDSLContext.java:531)
    at org.jooq.impl.Tools$3$1.block(Tools.java:6068)
    at java.base/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3780)
    at java.base/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3725)
    at org.jooq.impl.Tools$3.get(Tools.java:6065)
    at org.jooq.impl.DefaultDSLContext.transactionResult0(DefaultDSLContext.java:579)
    at org.jooq.impl.DefaultDSLContext.transactionResult(DefaultDSLContext.java:503)
    at org.jooq.impl.DefaultDSLContext.transaction(DefaultDSLContext.java:592)
    at stroom.db.util.JooqUtil.lambda$transaction$3(JooqUtil.java:287)
    at stroom.db.util.JooqUtil.context(JooqUtil.java:118)
    at stroom.db.util.JooqUtil.transaction(JooqUtil.java:287)
    at stroom.index.impl.db.IndexFieldDaoImpl.addFields(IndexFieldDaoImpl.java:103)
    at stroom.index.impl.IndexFieldServiceImpl.addFields(IndexFieldServiceImpl.java:47)
    at stroom.index.impl.IndexFieldServiceImpl.transferFieldsToDB(IndexFieldServiceImpl.java:71)
    at stroom.index.impl.IndexFieldServiceImpl.findFields(IndexFieldServiceImpl.java:53)
    at stroom.index.impl.IndexFieldServiceImpl.lambda$getIndexField$1(IndexFieldServiceImpl.java:104)
    at stroom.security.impl.SecurityContextImpl.useAsReadResult(SecurityContextImpl.java:390)
    at stroom.index.impl.IndexFieldServiceImpl.getIndexField(IndexFieldServiceImpl.java:91)
    at stroom.index.impl.IndexFieldProvidersImpl.getIndexField(IndexFieldProvidersImpl.java:68)
    at stroom.index.impl.IndexFieldCacheImpl.lambda$create$1(IndexFieldCacheImpl.java:62)
    at stroom.security.impl.SecurityContextImpl.asUserResult(SecurityContextImpl.java:322)
    at stroom.security.impl.SecurityContextImpl.asProcessingUserResult(SecurityContextImpl.java:353)
    at stroom.index.impl.IndexFieldCacheImpl.create(IndexFieldCacheImpl.java:61)
    at com.github.benmanes.caffeine.cache.LocalLoadingCache.lambda$newMappingFunction$3(LocalLoadingCache.java:183)
    at com.github.benmanes.caffeine.cache.LocalCache.lambda$statsAware$2(LocalCache.java:167)
    at com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$doComputeIfAbsent$14(BoundedLocalCache.java:2688)
    at java.base/java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1916)
    at com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:2686)
    at com.github.benmanes.caffeine.cache.BoundedLocalCache.computeIfAbsent(BoundedLocalCache.java:2669)
    at com.github.benmanes.caffeine.cache.LocalCache.computeIfAbsent(LocalCache.java:112)
    at com.github.benmanes.caffeine.cache.LocalLoadingCache.get(LocalLoadingCache.java:58)
    at stroom.cache.impl.LoadingStroomCacheImpl.get(LoadingStroomCacheImpl.java:47)
    at stroom.index.impl.IndexFieldCacheImpl.get(IndexFieldCacheImpl.java:77)
    at stroom.index.lucene980.SearchExpressionQueryBuilder.getTermQuery(SearchExpressionQueryBuilder.java:250)
    at stroom.index.lucene980.SearchExpressionQueryBuilder.getQuery(SearchExpressionQueryBuilder.java:130)
    at stroom.index.lucene980.SearchExpressionQueryBuilder.getQuery(SearchExpressionQueryBuilder.java:137)
    at stroom.index.lucene980.SearchExpressionQueryBuilder.buildQuery(SearchExpressionQueryBuilder.java:91)
    at stroom.index.lucene980.Lucene980HighlightProvider.getHighlights(Lucene980HighlightProvider.java:57)
    at stroom.search.impl.LuceneSearchProvider.createResultStore(LuceneSearchProvider.java:165)
    at stroom.view.impl.ViewSearchProvider.createResultStore(ViewSearchProvider.java:159)
    at stroom.query.common.v2.ResultStoreManager.getResultStore(ResultStoreManager.java:229)
    at stroom.analytics.impl.ScheduledQueryAnalyticExecutor.processScheduledQueryAnalytic(ScheduledQueryAnalyticExecutor.java:283)
    at stroom.analytics.impl.ScheduledQueryAnalyticExecutor.lambda$processScheduledQueryAnalytic$10(ScheduledQueryAnalyticExecutor.java:219)
    at stroom.analytics.impl.AnalyticErrorWriter.exec(AnalyticErrorWriter.java:69)
    at stroom.analytics.impl.ScheduledQueryAnalyticExecutor.lambda$processScheduledQueryAnalytic$11(ScheduledQueryAnalyticExecutor.java:216)
    at stroom.task.impl.TaskContextFactoryImpl.lambda$createFromConsumer$0(TaskContextFactoryImpl.java:181)
    at stroom.task.impl.TaskContextFactoryImpl.lambda$wrap$2(TaskContextFactoryImpl.java:253)
    at stroom.util.logging.LocationAwareLambdaLogger.logDurationIfDebugEnabled(LocationAwareLambdaLogger.java:307)
    at stroom.task.impl.TaskContextFactoryImpl.lambda$wrap$4(TaskContextFactoryImpl.java:253)
    at stroom.util.pipeline.scope.PipelineScopeRunnable.scopeResult(PipelineScopeRunnable.java:39)
    at stroom.task.impl.TaskContextFactoryImpl.lambda$wrap$5(TaskContextFactoryImpl.java:250)
    at stroom.task.impl.TaskContextFactoryImpl.lambda$wrap$6(TaskContextFactoryImpl.java:262)
    at stroom.security.impl.SecurityContextImpl.useAsReadResult(SecurityContextImpl.java:390)
    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    at java.base/java.lang.reflect.Method.invoke(Method.java:580)
    at com.google.inject.internal.DelegatingInvocationHandler.invoke(DelegatingInvocationHandler.java:50)
    at jdk.proxy2/jdk.proxy2.$Proxy120.useAsReadResult(Unknown Source)
    at stroom.task.impl.TaskContextFactoryImpl.lambda$wrap$7(TaskContextFactoryImpl.java:262)
    at stroom.security.impl.SecurityContextImpl.asUserResult(SecurityContextImpl.java:322)
    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    at java.base/java.lang.reflect.Method.invoke(Method.java:580)
    at com.google.inject.internal.DelegatingInvocationHandler.invoke(DelegatingInvocationHandler.java:50)
    at jdk.proxy2/jdk.proxy2.$Proxy120.asUserResult(Unknown Source)
    at stroom.task.impl.TaskContextFactoryImpl.lambda$wrap$11(TaskContextFactoryImpl.java:260)
    at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
    at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
    at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:124)
    at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
    at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:916)
    at com.mysql.cj.jdbc.ClientPreparedStatement.execute(ClientPreparedStatement.java:354)
    at com.zaxxer.hikari.pool.ProxyPreparedStatement.execute(ProxyPreparedStatement.java:44)
    at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.execute(HikariProxyPreparedStatement.java)
    at org.jooq.tools.jdbc.DefaultPreparedStatement.execute(DefaultPreparedStatement.java:219)
    at org.jooq.impl.AbstractQuery.execute(AbstractQuery.java:445)
    at org.jooq.impl.AbstractDMLQuery.execute(AbstractDMLQuery.java:1024)
    at org.jooq.impl.AbstractQuery.execute(AbstractQuery.java:346)
    ... 72 common frames omitted
------------------------
LATEST DETECTED DEADLOCK
------------------------
2024-04-18 06:14:43 140362304165632
*** (1) TRANSACTION:
TRANSACTION 18965586209, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 9 lock struct(s), heap size 1128, 8 row lock(s)
MySQL thread id 13, OS thread handle 140366847276800, query id 38244 xxx.xxx.xxx.xxx stroomuser update
insert into `index_field` (`fk_index_field_source_id`, `type`, `name`, `analyzer`, `indexed`, `stored`, `term_positions`, `case_sensitive`) values (1, 7, 'EventId', 'Keyword', 1, 1, 0, 0), (1, 7, 'StreamId', 'Keyword', 1, 1, 0, 0), (1, 6, 'Event Time', 'Keyword', 1, 1, 0, 0), (1, 7, 'Log Level', 'Keyword', 1, 1, 0,0), (1, 7, 'xxxxx', 'Keyword', 1, 1, 0, 0), (1, 7, 'xxxxx', 'Keyword', 1, 0, 0, 0), (1, 7, 'xxxx', 'Keyword', 1, 0, 0, 0), (1, 7, 'xxxxx', 'Keyword', 1, 1, 0, 0), (1, 7, 'xxxxx', 'Keyword', 1, 0, 0, 0), (1, 7, 'xxxxxxxx', 'Keyword', 1, 0, 0, 0) on duplicate key update `index_field`.`fk_index_field_source_id` = 1

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 3223446 page no 4 n bits 112 index PRIMARY of table `stroom`.`index_field` trx id 18965586209 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 3223446 page no 4 n bits 112 index PRIMARY of table `stroom`.`index_field` trx id 18965586209 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) TRANSACTION:
TRANSACTION 18965586208, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 8 lock struct(s), heap size 1128, 6 row lock(s)
MySQL thread id 11, OS thread handle 140366849390336, query id 38245 xxx.xxx.xxx.xxx stroomuser update
insert into `index_field` (`fk_index_field_source_id`, `type`, `name`, `analyzer`, `indexed`, `stored`, `term_positions`, `case_sensitive`) values (2, 0, 'StreamId', 'Numeric', 1, 1, 0, 0), (2, 0, 'EventId', 'Numeric', 1, 1, 0, 0), (2, 6, 'xxxxxxxxxxxx', 'Keyword', 1, 0, 0, 0), (2, 7, 'xxxxxxxxxx', 'Alpha numeric', 1, 0, 0,0), (2, 7, 'xxxxxxxxxxx', 'Alpha numeric', 1, 0, 0, 0), (2, 7, 'xxxxxxxxxxxxx', 'Alpha numeric', 1, 0, 0, 0), (2, 7, 'xxxxxxxxxxxx', 'Alpha numeric', 1, 0, 0, 0), (2, 7, 'xxxxxxx', 'Alpha numeric', 1, 0, 0, 0), (2, 7, 'xxxx', 'Alpha numeric', 1, 0, 0, 0), (2, 7, 'Outcome', 'Alpha numeric', 1, 0, 0, 0), (2, 7, 'xxxxxx', 'Alpha numeric', 1, 0, 0, 0), (2, 7, 'xxxxxx', 'Keyword', 1, 0, 0, 0), (2, 7, 'xxxxxx', 'Keyword', 1, 0, 0, 0), (2, 7, 'ParentActivity', 'Keyword', 0, 0, 0, 0), (2, 7, 'ChildActivity', 'Keyword', 0, 0, 0, 0), (2, 7, 'Outcome Description', 'Keyword', 0, 0, 0, 0), (2, 7, 'Device HostName', 'Keyword', 0, 0, 0, 0) on duplicate key update `index_field`.`fk_index_field_source_id` = 2
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 3223446 page no 4 n bits 112 index PRIMARY of table `stroom`.`index_field` trx id 18965586208 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 3223446 page no 4 n bits 112 index PRIMARY of table `stroom`.`index_field` trx id 18965586208 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

*** WE ROLL BACK TRANSACTION (2)
at055612 commented 5 months ago

Fixed in > 7.3-beta.20