Версия радиуса:
version 5.1 build 276 from 07.04.2011 12:20:07
Сегодня массово сбрасывали сессии на NAS-ах, словили такую проблему:
радиус съел все разрешенные коннекты к базе и не освобождал их до перезагрузки.
Сделал jstack, jmap, сохранили логи, сел разбираться.
В jstack половина потоков висит на ожидании получения коннекта:
Код:
"radiusListener-p-3-t-311" prio=10 tid=0x0000000041cc2800 nid=0x2c75 in Object.wait() [0x00007fd229ad9000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:942)
- locked <0x00007fd28cb2fb60> (a org.apache.commons.pool.impl.GenericObjectPool)
at ru.bitel.bgbilling.server.util.DefaultServerSetup.getDBConnectionFromPool(DefaultServerSetup.java:499)
at ru.bitel.bgbilling.server.util.DefaultServerSetup.getDBTrashOrMasterConnectionFromPool(DefaultServerSetup.java:703)
at bitel.billing.server.script.bean.ScriptMachine.logFunctionProcess(ScriptMachine.java:258)
at bitel.billing.server.script.bean.ScriptMachine.runScript(ScriptMachine.java:163)
at bitel.billing.server.script.bean.event.EventProcessor.processContractEvent(EventProcessor.java:313)
at bitel.billing.server.script.bean.event.EventProcessor.processEvent(EventProcessor.java:231)
at bitel.billing.server.script.bean.event.EventProcessor.processEvent(EventProcessor.java:215)
at bitel.billing.server.script.bean.event.EventProcessor.processEvent(EventProcessor.java:194)
at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accessRequest(RadiusProcessor.java:328)
at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.run(RadiusListenerWorker.java:130)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:40)
Вторая половина висит на ожидании входа в synchronized метод bitel.billing.server.processor.LC_LimitChecker.canComeIn() :
Код:
"radiusListener-p-3-t-314" prio=10 tid=0x0000000040d94800 nid=0x2c78 waiting for monitor entry [0x00007fd2297d5000]
java.lang.Thread.State: BLOCKED (on object monitor)
at bitel.billing.server.processor.LC_LimitChecker.canComeIn(LC_LimitChecker.java:73)
- waiting to lock <0x00007fd28cbb8b58> (a ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor$1)
at ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor.authorization(DialUpRadiusProcessor.java:890)
at ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor.authorization(DialUpRadiusProcessor.java:1)
at ru.bitel.bgbilling.kernel.network.radius.AbstractRadiusProcessor.authenticationImpl(AbstractRadiusProcessor.java:411)
at ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor.authenticationImpl(DialUpRadiusProcessor.java:594)
at ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor.authenticationImpl(DialUpRadiusProcessor.java:1)
at ru.bitel.bgbilling.kernel.network.radius.AbstractRadiusProcessor.authentication(AbstractRadiusProcessor.java:192)
at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.authentication(RadiusSession.java:114)
at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.accessRequest(RadiusSession.java:92)
at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accessRequest(RadiusProcessor.java:316)
at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.run(RadiusListenerWorker.java:130)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:40)
А заткнулось всё на этом потоке:
Код:
"radiusListener-p-3-t-319" prio=10 tid=0x0000000041c67800 nid=0x2c7d in Object.wait() [0x00007fd2292d0000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:942)
- locked <0x00007fd28cb2fb60> (a org.apache.commons.pool.impl.GenericObjectPool)
at ru.bitel.bgbilling.server.util.DefaultServerSetup.getDBConnectionFromPool(DefaultServerSetup.java:499)
at bitel.billing.server.processor.LC_CheckingLogin.getStatus(LC_CheckingLogin.java:39)
at bitel.billing.server.processor.LC_CheckingLogin.canLoginComeIn(LC_CheckingLogin.java:162)
at bitel.billing.server.processor.LC_LimitChecker.canComeIn(LC_LimitChecker.java:79)
- locked <0x00007fd28cbb8b58> (a ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor$1)
at ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor.authorization(DialUpRadiusProcessor.java:890)
at ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor.authorization(DialUpRadiusProcessor.java:1)
at ru.bitel.bgbilling.kernel.network.radius.AbstractRadiusProcessor.authenticationImpl(AbstractRadiusProcessor.java:411)
at ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor.authenticationImpl(DialUpRadiusProcessor.java:594)
at ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor.authenticationImpl(DialUpRadiusProcessor.java:1)
at ru.bitel.bgbilling.kernel.network.radius.AbstractRadiusProcessor.authentication(AbstractRadiusProcessor.java:192)
at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.authentication(RadiusSession.java:114)
at ru.bitel.bgbilling.kernel.network.radius.RadiusSession.accessRequest(RadiusSession.java:92)
at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accessRequest(RadiusProcessor.java:316)
at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.run(RadiusListenerWorker.java:130)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:40)
Как я понимаю, при вызове метода ru.bitel.bgbilling.modules.dialup.radius.DialUpRadiusProcessor.authorization() тред уже берёт один коннект к базе из пула.
Затем он запускает метод bitel.billing.server.processor.LC_LimitChecker.canComeIn(), в недрах которого коннект к базе получается заново.
Получается, что первый коннект он успел схватить, а на получении второго застрял, т.к. они закончились.
Дальше т.к. метод canComeIn() - синхронизирован, то все остальные потоки авторизации затыкаются либо на нём, либо на получении коннекта к базе.
Как-то так, в целом. Правда не совсем понятно, как куча потоков авторизации, ожидающих canComeIn(), получила первый коннект к мускулю, а наш поток так и остался ждать своей очереди.
Вот.
Могу выслать на почту, если надо:
collector.log.err.2011-05-31-07:26
connection.log.err.2011-05-31-07:26
error.log.err.2011-05-31-07:26
innodbstat.log.2011-05-31-07:26
mq.log.err.2011-05-31-07:26
mysql.proc.2011-05-31-07:26
processor.log.err.2011-05-31-07:26
radius.jmap.2011-05-31-07:26
radius.jstack.2011-05-31-07:26
radius.log.err.2011-05-31-07:26
radius.out.err.2011-05-31-07:26
rad_ps.2011-05-31-07:26
script.log.err.2011-05-31-07:26
status.log.2011-05-31-07:26