Блокировка запуска пула соединений c3po с помощью Zipkin TracingStatementInterceptor - PullRequest
0 голосов
/ 10 мая 2019

Попытка добавить инструментарий трассировки Zipkin mysql, включив следующую библиотеку в Spring Boot Application

compile group: 'io.zipkin.brave', name: 'brave-instrumentation-mysql', version: '5.6.3'

И добавив следующее в мою строку подключения jdbc:

?statementInterceptors=brave.mysql.TracingStatementInterceptor

Существующая БДсоединение использует пул соединений c3po, настроенный следующим образом:

<bean id="dataSourceBean" class="com.mchange.v2.c3p0.ComboPooledDataSource" destroy-method="close" primary="true">
    <property name="driverClass" value="${db.driver}" />
    <property name="jdbcUrl" value="${db.url}" />
    <property name="user" value="${db.username}" />
    <property name="password" value="${db.password}" />
    <property name="initialPoolSize" value="${db.initial.pool.size}" />
    <property name="minPoolSize" value="${db.min.pool.size}" />
    <property name="maxPoolSize" value="${db.max.pool.size}" />
    <property name="idleConnectionTestPeriod" value="30" />
    <property name="maxIdleTimeExcessConnections" value="120" />
</bean>

, но при запуске службы при попытке получения соединений из пула работает проблема:

2019-05-09 22:54:40.752  WARN [api,,,] 31975 --- [-AdminTaskTimer] c.m.v.a.ThreadPoolAsynchronousRunner     : com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@222a008d -- APPARENT DEADLOCK!!! Complete Status: 
    Managed Threads: 3
    Active Threads: 3
    Active Tasks: 
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@5cf72aaf
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kflta218cyxuc1srbxxo|30f51f8a]-HelperThread-#0
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@67c13f4f
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kflta218cyxuc1srbxxo|30f51f8a]-HelperThread-#1
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@dff1fcc
            on thread: C3P0PooledConnectionPoolManager[identityToken->z8kflta218cyxuc1srbxxo|30f51f8a]-HelperThread-#2
    Pending Tasks: 
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@775717e4
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@1290e9f3
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@7cc597a9
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@9b1e682
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@46963867
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@53dc8e37
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@3f4233a
Pool thread stack traces:
    Thread[C3P0PooledConnectionPoolManager[identityToken->z8kflta218cyxuc1srbxxo|30f51f8a]-HelperThread-#0,5,main]
        org.springframework.cloud.context.scope.GenericScope$BeanLifecycleWrapper.getBean(GenericScope.java:388)
        org.springframework.cloud.context.scope.GenericScope.get(GenericScope.java:186)
        org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:353)
        org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:199)
        org.springframework.aop.target.SimpleBeanTargetSource.getTarget(SimpleBeanTargetSource.java:35)
        org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:672)
        brave.sampler.Sampler$$EnhancerBySpringCGLIB$$d8298fbe.isSampled(<generated>)
        brave.Tracer.nextContext(Tracer.java:252)
        brave.Tracer.newRootContext(Tracer.java:212)
        brave.Tracer.newTrace(Tracer.java:142)
        brave.Tracer.nextSpan(Tracer.java:436)
        brave.propagation.ThreadLocalSpan.next(ThreadLocalSpan.java:119)
        brave.mysql.TracingStatementInterceptor.preProcess(TracingStatementInterceptor.java:33)
        com.mysql.jdbc.NoSubInterceptorWrapper.preProcess(NoSubInterceptorWrapper.java:71)
        com.mysql.jdbc.MysqlIO.invokeStatementInterceptorsPre(MysqlIO.java:3007)
        com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2671)
        com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2828)
        com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2777)
        com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1651)
        com.mysql.jdbc.ConnectionImpl.loadServerVariables(ConnectionImpl.java:4215)
        com.mysql.jdbc.ConnectionImpl.initializePropsFromServer(ConnectionImpl.java:3609)
        com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2550)
        com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2320)
        com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:834)
        com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:46)
        sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
        com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:416)
        com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:347)
        com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:175)
        com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:220)
        com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:206)
        com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:203)
        com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1138)
        com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1125)
        com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:44)
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1870)
        com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)
    Thread[C3P0PooledConnectionPoolManager[identityToken->z8kflta218cyxuc1srbxxo|30f51f8a]-HelperThread-#1,5,main]
        org.springframework.cloud.context.scope.GenericScope$BeanLifecycleWrapper.getBean(GenericScope.java:388)
        org.springframework.cloud.context.scope.GenericScope.get(GenericScope.java:186)
        org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:353)
        org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:199)
        org.springframework.aop.target.SimpleBeanTargetSource.getTarget(SimpleBeanTargetSource.java:35)
        org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:672)
        brave.sampler.Sampler$$EnhancerBySpringCGLIB$$d8298fbe.isSampled(<generated>)
        brave.Tracer.nextContext(Tracer.java:252)
        brave.Tracer.newRootContext(Tracer.java:212)
        brave.Tracer.newTrace(Tracer.java:142)
        brave.Tracer.nextSpan(Tracer.java:436)
        brave.propagation.ThreadLocalSpan.next(ThreadLocalSpan.java:119)
        brave.mysql.TracingStatementInterceptor.preProcess(TracingStatementInterceptor.java:33)
        com.mysql.jdbc.NoSubInterceptorWrapper.preProcess(NoSubInterceptorWrapper.java:71)
        com.mysql.jdbc.MysqlIO.invokeStatementInterceptorsPre(MysqlIO.java:3007)
        com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2671)
        com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2828)
        com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2777)
        com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1651)
        com.mysql.jdbc.ConnectionImpl.loadServerVariables(ConnectionImpl.java:4215)
        com.mysql.jdbc.ConnectionImpl.initializePropsFromServer(ConnectionImpl.java:3609)
        com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2550)
        com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2320)
        com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:834)
        com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:46)
        sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
        com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:416)
        com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:347)
        com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:175)
        com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:220)
        com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:206)
        com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:203)
        com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1138)
        com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1125)
        com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:44)
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1870)
        com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)
    Thread[C3P0PooledConnectionPoolManager[identityToken->z8kflta218cyxuc1srbxxo|30f51f8a]-HelperThread-#2,5,main]
        org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:204)
        org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:318)
        org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:199)
        org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:392)
        org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1305)
        org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1144)
        org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:555)
        org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:515)
        org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$1(AbstractBeanFactory.java:356)
        org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$570/35986993.getObject(Unknown Source)
        org.springframework.cloud.context.scope.GenericScope$BeanLifecycleWrapper.getBean(GenericScope.java:389)
        org.springframework.cloud.context.scope.GenericScope.get(GenericScope.java:186)
        org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:353)
        org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:199)
        org.springframework.aop.target.SimpleBeanTargetSource.getTarget(SimpleBeanTargetSource.java:35)
        org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:672)
        brave.sampler.Sampler$$EnhancerBySpringCGLIB$$d8298fbe.isSampled(<generated>)
        brave.Tracer.nextContext(Tracer.java:252)
        brave.Tracer.newRootContext(Tracer.java:212)
        brave.Tracer.newTrace(Tracer.java:142)
        brave.Tracer.nextSpan(Tracer.java:436)
        brave.propagation.ThreadLocalSpan.next(ThreadLocalSpan.java:119)
        brave.mysql.TracingStatementInterceptor.preProcess(TracingStatementInterceptor.java:33)
        com.mysql.jdbc.NoSubInterceptorWrapper.preProcess(NoSubInterceptorWrapper.java:71)
        com.mysql.jdbc.MysqlIO.invokeStatementInterceptorsPre(MysqlIO.java:3007)
        com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2671)
        com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2828)
        com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2777)
        com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1651)
        com.mysql.jdbc.ConnectionImpl.loadServerVariables(ConnectionImpl.java:4215)
        com.mysql.jdbc.ConnectionImpl.initializePropsFromServer(ConnectionImpl.java:3609)
        com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2550)
        com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2320)
        com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:834)
        com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:46)
        sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
        com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:416)
        com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:347)
        com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:175)
        com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:220)
        com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:206)
        com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:203)
        com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1138)
        com.mchange.v2.resourcepool.BasicResourcePool.doAcquireAndDecrementPendingAcquiresWithinLockOnSuccess(BasicResourcePool.java:1125)
        com.mchange.v2.resourcepool.BasicResourcePool.access$700(BasicResourcePool.java:44)
        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask.run(BasicResourcePool.java:1870)
        com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:696)

1 Ответ

0 голосов
/ 10 мая 2019

Похоже, что трассировка вызывает старомодные потоки заморозки с блокировкой в ​​обратном порядке блокировки, которые пытаются получить новые соединения.

Последний из трех заблокированных потоков пытается получитьблокировка какого-то синглтона или боба .Он уже прошел и предположительно получил блокировку на GenericScope.

Два других потока пытаются получить блокировку на GenericScope, который предположительно имеет первый поток.

Неожиданный возврат из кода zipkin в пружину приводит к тупику.c3p0 имеет пул потоков фиксированного размера, который замечает, когда все его потоки (только 3 здесь, c3p0 по умолчанию) постоянно замораживаются, затем (довольно правильно в этом случае) объявляет взаимоблокировку и заменяет заблокированные потоки в надеждевосстановления.

c3p0 восстанавливается?Это редкий или частый тупик?Вы не можете легко сделать, чтобы предотвратить этот тупик, я думаю, вы либо должны будете это терпеть, либо обходиться без инструментов.

...