reportportal / service-api

Report portal. Main API Service
Apache License 2.0
44 stars 65 forks source link

[BUG] ERROR: deadlock detected on 'function update_executions_statistics()' #1950

Closed shaburov closed 3 days ago

shaburov commented 6 months ago

rp.reporting.async=false rp.rerun=true

When broadcasting results to RP -> PSQLException: ERROR: deadlock detected The problem is floating and reproduced for me only for rp.rerun=true

image

Client (com.epam.reportportal:client-java:5.1.24)

20:04:17.343 ERROR - [55] ReportPortal execution error
retrofit2.adapter.rxjava2.HttpException: HTTP 500 

Server (Build: 5.11.0)

2024-03-18 17:32:58.901 ERROR 1 --- [io-8585-exec-63] o.h.engine.jdbc.spi.SqlExceptionHelper   : ERROR: deadlock detected
  Detail: Process 2704039 waits for ShareLock on transaction 40363; blocked by process 2706940.
Process 2706940 waits for ShareLock on transaction 40372; blocked by process 2704039.
  Hint: See server log for query details.
  Where: while inserting index tuple (46,20) in relation "statistics"
SQL statement "INSERT INTO statistics (s_counter, statistics_field_id, item_id)
        VALUES (1, executions_field_total_id, unnest(processed_test_item.arr_path))
        ON CONFLICT (statistics_field_id,item_id) DO UPDATE SET s_counter = statistics.s_counter + 1"
PL/pgSQL function update_executions_statistics() line 71 at SQL statement
unnamed portal with parameters: $1 = '0.238', $2 = '2024-03-18 17:32:57.701+00', $3 = 'PASSED', $4 = '4894'
2024-03-18 17:32:58.902  INFO 1 --- [io-8585-exec-63] o.h.e.j.b.internal.AbstractBatchImpl     : HHH000010: On release of batch it still contained JDBC statements
2024-03-18 17:32:58.909 ERROR 1 --- [io-8585-exec-63] c.e.t.r.c.e.rest.RestExceptionHandler    : Handled error: 

org.springframework.dao.CannotAcquireLockException: could not execute statement; SQL [n/a]; nested exception is org.hibernate.exception.LockAcquisitionException: could not execute statement
        at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:267)
        at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:233)
        at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:566)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:743)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:711)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:654)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:407)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708)
        at com.epam.ta.reportportal.core.item.impl.FinishTestItemHandlerImpl$$EnhancerBySpringCGLIB$$7da3474c.finishTestItem(<generated>)
        at com.epam.ta.reportportal.ws.controller.TestItemController.finishTestItem(TestItemController.java:163)
        at com.epam.ta.reportportal.ws.controller.TestItemController$$FastClassBySpringCGLIB$$b0260678.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:793)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
        at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:67)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:708)
        at com.epam.ta.reportportal.ws.controller.TestItemController$$EnhancerBySpringCGLIB$$cb7fa933.finishTestItem(<generated>)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
        at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150)
        at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117)
        at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895)
        at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)
        at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
        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.doPut(FrameworkServlet.java:920)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:558)
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:623)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:209)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
        at org.springframework.web.multipart.support.MultipartFilter.doFilterInternal(MultipartFilter.java:125)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:352)
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:117)
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:126)
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:120)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:131)
        at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:85)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:100)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:164)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.oauth2.provider.authentication.OAuth2AuthenticationProcessingFilter.doFilter(OAuth2AuthenticationProcessingFilter.java:182)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:107)
        at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:93)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90)
        at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:117)
        at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:62)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:361)
        at org.springframework.security.web.session.DisableEncodeUrlFilter.doFilterInternal(DisableEncodeUrlFilter.java:42)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        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.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:354)
        at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
        at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
        at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
        at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:96)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
        at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:168)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:481)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:130)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:390)
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:928)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1794)
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
        at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
        at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement
        at org.hibernate.dialect.PostgreSQL81Dialect$4.convert(PostgreSQL81Dialect.java:500)
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:37)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:200)
        at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46)
        at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3571)
        at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3438)
        at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3870)
        at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:202)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
        at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
        at java.base/java.util.LinkedHashMap.forEach(LinkedHashMap.java:986)
        at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
        at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:344)
        at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
        at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:107)
        at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1407)
        at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:489)
        at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3303)
        at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2438)
        at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:449)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:183)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$300(JdbcResourceLocalTransactionCoordinatorImpl.java:40)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:281)
        at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:101)
        at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:562)
        ... 116 common frames omitted
Caused by: org.postgresql.util.PSQLException: ERROR: deadlock detected
  Detail: Process 2704039 waits for ShareLock on transaction 40363; blocked by process 2706940.
Process 2706940 waits for ShareLock on transaction 40372; blocked by process 2704039.
  Hint: See server log for query details.
  Where: while inserting index tuple (46,20) in relation "statistics"
SQL statement "INSERT INTO statistics (s_counter, statistics_field_id, item_id)
        VALUES (1, executions_field_total_id, unnest(processed_test_item.arr_path))
        ON CONFLICT (statistics_field_id,item_id) DO UPDATE SET s_counter = statistics.s_counter + 1"
PL/pgSQL function update_executions_statistics() line 71 at SQL statement
unnamed portal with parameters: $1 = '0.238', $2 = '2024-03-18 17:32:57.701+00', $3 = 'PASSED', $4 = '4894'
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2676)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:356)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190)
        at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:152)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
        at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:197)
        ... 138 common frames omitted

2024-03-18 17:32:58.910 ERROR 1 --- [io-8585-exec-63] .t.r.c.e.r.ReportPortalExceptionResolver : ReportPortalExceptionResolver > could not execute statement; SQL [n/a]; nested exception is org.hibernate.exception.LockAcquisitionException: could not execute statement
shaburov commented 6 months ago

Same issue #1720

Pink-Bumblebee commented 6 months ago

Thank you for notice. We will check issue and try to fix it.

shaburov commented 6 months ago

Suspected conflict on table update. The error occurs only at the end of the run when processing the last 20-50 results.

image

image

Maby interruptInProgressItems is called before all test results are processed (queue or rp.reporting.async=true/false) by finishTestItem calls?

    at com.epam.ta.reportportal.ws.controller.TestItemController.finishTestItem(TestItemController.java:163)

image

VeranikaRymzha commented 3 days ago

Hello @shaburov , I wanted to let you know that the ReportPortal 24.2 version is now live, along with the improvement you've requested. So I will close this GitHub issue.

You can find more details about the new features and enhancements in the release notes. Feel free to try it out and share any feedback you may have.

Have a great day!