forum.bitel.ru • Просмотр темы - accounting queue is full на границе суток

Сообщения без ответов | Активные темы

Список форумов » BGBilling » Модули Интернета » Модуль Inet

Часовой пояс: UTC + 5 часов [ Летнее время ]

accounting queue is full на границе суток

Страница 1 из 1

[ Сообщений: 13 ]

Версия для печати

Пред. тема | След. тема

Автор

Сообщение

fmaks

Заголовок сообщения: accounting queue is full на границе суток

Добавлено: 29 авг 2017, 16:17

Зарегистрирован: 20 окт 2016, 00:34
Сообщения: 82
Карма: 0

Здраствуйте.
Перенёс я сервисы access+accounting на новый живой сервер (8 полноценных ядер), теперь получаю каждый день
в 00:00 письмо

Код:

ID события: radius.wait.thread
Время регистрации события: 29.08.2017 00:00:17
Хост сервера: hostname not resolved: bginetrad110.xxx.localdomain: bginetrad110.xxx.localdomain: Name or service not known

В рамках отведенного переменными количества потоков threadCount=14 и размером очереди обработки maxQueueSize=200 RADIUS сервер не успеевает производить обработку аккаунтинг запросов.
Возможная причина - загруженность базы данных.

Radius:
  accounting-requests per minute start: 6; stop: 2; update: 1578
  access-requests per minute accept: 0; reject: 0
  ignore per minute access-request: 0; accounting-update: 0
Stack trace:

"MySQL Statement Cancellation Timer" Id=113 TIMED_WAITING on java.util.TaskQueue@4aa86324
   at java.lang.Object.wait(Native Method)
   -  waiting on java.util.TaskQueue@4aa86324
   at java.util.TimerThread.mainLoop(Timer.java:552)
   at java.util.TimerThread.run(Timer.java:505)

"MySQL Statement Cancellation Timer" Id=112 TIMED_WAITING on java.util.TaskQueue@446f8401
   at java.lang.Object.wait(Native Method)
   -  waiting on java.util.TaskQueue@446f8401
   at java.util.TimerThread.mainLoop(Timer.java:552)
   at java.util.TimerThread.run(Timer.java:505)

...

"ActiveMQ Session Task" Id=105 TIMED_WAITING on java.util.concurrent.SynchronousQueue$TransferStack@3a2f24e9
   at sun.misc.Unsafe.park(Native Method)
   -  waiting on java.util.concurrent.SynchronousQueue$TransferStack@3a2f24e9
   at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at java.lang.Thread.run(Thread.java:745)

"pool-4-thread-1" Id=103 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@631c5f4d
   at sun.misc.Unsafe.park(Native Method)
   -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@631c5f4d
   at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at java.lang.Thread.run(Thread.java:745)

...

"rdsLstnr-p-8-t-14" Id=81 RUNNABLE
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:171)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:100)
   at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:143)
   at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:173)
   -  locked com.mysql.jdbc.util.ReadAheadInputStream@534b9c56
   at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2954)
   at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3375)
   at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365)
   at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805)
   at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)
   at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)
   at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2547)
   -  locked com.mysql.jdbc.JDBC4Connection@5040e912
   at com.mysql.jdbc.ConnectionImpl.commit(ConnectionImpl.java:1616)
   -  locked com.mysql.jdbc.JDBC4Connection@5040e912
   at org.apache.commons.dbcp.DelegatingConnection.commit(DelegatingConnection.java:334)
   at ru.bitel.bgbilling.server.util.PoolGuardConnectionWrapper.commit(PoolGuardConnectionWrapper.java:74)
   at ru.bitel.bgbilling.modules.inet.accounting.Accounting.sessionFinish(Accounting.java:1865)
   at ru.bitel.bgbilling.modules.inet.accounting.InetConnectionRuntime.splitSessionImpl(InetConnectionRuntime.java:1188)
   at ru.bitel.bgbilling.modules.inet.accounting.InetConnectionCallRuntime.splitSession(InetConnectionCallRuntime.java:506)
   at ru.bitel.bgbilling.modules.inet.accounting.InetConnectionRuntime.trySplitSession(InetConnectionRuntime.java:994)
   at ru.bitel.bgbilling.modules.inet.accounting.InetConnectionCallRuntime.trySplitSession(InetConnectionCallRuntime.java:454)
   at ru.bitel.bgbilling.modules.inet.accounting.InetConnectionCallRuntime.trySplitSession(InetConnectionCallRuntime.java:450)
   at ru.bitel.bgbilling.modules.inet.accounting.Accounting.processRadiusPacket(Accounting.java:1893)
   ...

   Number of locked synchronizers = 2
   - java.util.concurrent.locks.ReentrantLock$NonfairSync@6d590c8c
   - java.util.concurrent.ThreadPoolExecutor$Worker@2a9d606

"rdsLstnr-p-8-t-13" Id=80 RUNNABLE
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:171)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:100)
   at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:143)
   at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:173)
   -  locked com.mysql.jdbc.util.ReadAheadInputStream@45e70179
   at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2954)
   at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3375)
   at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365)
   at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805)
   at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)
   at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)
   at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)
   -  locked com.mysql.jdbc.JDBC4Connection@4ac19cbf
   at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)
   -  locked com.mysql.jdbc.JDBC4Connection@4ac19cbf
   at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2073)
   -  locked com.mysql.jdbc.JDBC4Connection@4ac19cbf
   at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2009)
   -  locked com.mysql.jdbc.JDBC4Connection@4ac19cbf
   at com.mysql.jdbc.PreparedStatement.executeLargeUpdate(PreparedStatement.java:5094)
   at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1994)
   at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
   at ru.bitel.bgbilling.modules.inet.accounting.SessionFlushingManager.merge(SessionFlushingManager.java:932)
   at ru.bitel.bgbilling.modules.inet.accounting.SessionFlushingManager.flush(SessionFlushingManager.java:387)
   at ru.bitel.bgbilling.modules.inet.accounting.Accounting.sessionFinish(Accounting.java:1826)
   at ru.bitel.bgbilling.modules.inet.accounting.InetConnectionRuntime.splitSessionImpl(InetConnectionRuntime.java:1188)
   ...

   Number of locked synchronizers = 2
   - java.util.concurrent.locks.ReentrantLock$NonfairSync@1d1ee48c
   - java.util.concurrent.ThreadPoolExecutor$Worker@52d83532

...

"DestroyJavaVM" Id=67 RUNNABLE

"InetRadiusListener" Id=66 RUNNABLE
   at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
   at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
   at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
   at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
   -  locked sun.nio.ch.Util$3@4dea0395
   -  locked java.util.Collections$UnmodifiableSet@5459acad
   -  locked sun.nio.ch.EPollSelectorImpl@7f77da
   at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
   at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
   at ru.bitel.common.io.DatagramChannelListener.run(DatagramChannelListener.java:193)
   at java.lang.Thread.run(Thread.java:745)

...

"nas-ex-service-p-20-t-1" Id=62 TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6636ff6e
   at sun.misc.Unsafe.park(Native Method)
   -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6636ff6e
   at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
   at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
   at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
   at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at java.lang.Thread.run(Thread.java:745)
   at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46)

"worker-p-18-t-1" Id=60 TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@7b5dae96
   at sun.misc.Unsafe.park(Native Method)
   -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@7b5dae96
   at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
   at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
   at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
   at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at java.lang.Thread.run(Thread.java:745)
   at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46)

...

"accwrkr-system-p-14-t-1" Id=58 TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@19c223b6
   at sun.misc.Unsafe.park(Native Method)
   -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@19c223b6
   at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
   at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
   at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
   at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at java.lang.Thread.run(Thread.java:745)
   at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46)

"accwrkr-3-p-13-t-1" Id=57 TIMED_WAITING on java.util.concurrent.locks.ReentrantLock$NonfairSync@54004ac owned by "rdsLstnr-p-8-t-7" Id=74
   at sun.misc.Unsafe.park(Native Method)
   -  waiting on java.util.concurrent.locks.ReentrantLock$NonfairSync@54004ac
   at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireNanos(AbstractQueuedSynchronizer.java:934)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireNanos(AbstractQueuedSynchronizer.java:1247)
   at java.util.concurrent.locks.ReentrantLock.tryLock(ReentrantLock.java:442)
   at ru.bitel.bgbilling.kernel.contract.runtime.ContractRuntime.tryLock(ContractRuntime.java:165)
   at ru.bitel.bgbilling.modules.inet.runtime.InetServRuntime.tryLock(InetServRuntime.java:815)
   at ru.bitel.bgbilling.modules.inet.accounting.worker.SessionFinishWorker.runImpl(SessionFinishWorker.java:100)
   at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:86)
   at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
   at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
   at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at java.lang.Thread.run(Thread.java:745)
   at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46)

..

"event-proc-p-2-t-1" Id=50 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@198633ed
   at sun.misc.Unsafe.park(Native Method)
   -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@198633ed
   at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:403)
   at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at java.lang.Thread.run(Thread.java:745)
   at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46)

...

"Thread-11" Id=27 RUNNABLE
   at sun.management.ThreadImpl.dumpThreads0(Native Method)
   at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:454)
   at bitel.billing.server.admin.errorlog.AlarmSender.dumpStack(AlarmSender.java:353)
   -  locked java.lang.Class@747e77cc
   at bitel.billing.server.admin.errorlog.AlarmSender.run(AlarmSender.java:276)

"InactivityMonitor WriteCheck" Id=24 TIMED_WAITING on java.util.TaskQueue@2d1605aa
   at java.lang.Object.wait(Native Method)
   -  waiting on java.util.TaskQueue@2d1605aa
   at java.util.TimerThread.mainLoop(Timer.java:552)
   at java.util.TimerThread.run(Timer.java:505)

"InactivityMonitor ReadCheck" Id=23 TIMED_WAITING on java.util.TaskQueue@e99ee94
   at java.lang.Object.wait(Native Method)
   -  waiting on java.util.TaskQueue@e99ee94
   at java.util.TimerThread.mainLoop(Timer.java:552)
   at java.util.TimerThread.run(Timer.java:505)

"ActiveMQ Transport: tcp:///192.168.254.253:61616" Id=22 RUNNABLE (in native)
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:171)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:50)
   at org.apache.activemq.transport.tcp.TcpTransport$2.fill(TcpTransport.java:576)
   at org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:58)
   at org.apache.activemq.transport.tcp.TcpTransport$2.read(TcpTransport.java:561)
   at java.io.DataInputStream.readInt(DataInputStream.java:387)
   at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:269)
   at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:227)
   at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:219)
   at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:202)
   at java.lang.Thread.run(Thread.java:745)

"ActiveMQConnection[ID:bginetrad110.xxx.localdomain-45976-1503920396660-0:1] Scheduler" Id=20 WAITING on java.util.TaskQueue@5d97d0a4
   at java.lang.Object.wait(Native Method)
   -  waiting on java.util.TaskQueue@5d97d0a4
   at java.lang.Object.wait(Object.java:502)
   at java.util.TimerThread.mainLoop(Timer.java:526)
   at java.util.TimerThread.run(Timer.java:505)
...

Полное сообщение со стектрейсом в приложенном файле.

Пытался смотреть на mysql (5.5) SHOW PROCESSLIST при переходе суток, пустота.
В смысле что-то порядка 100 процессов в sleep, проскакивал INSERT.
По top wait-ов практически нет.
Сервак БД достаточно живой 32Гига + 24ядра, wait-ов как бы не наблюдается.
База порядка 160Гб.

activemq в kahadb: db-154771.log db.data db.redo lock, т.е. фактически пусто,
через её web-морду смотрел, сообщения вроде как не копятся, pending: 0.
Добавил ей памяти memoryLimit 256m, результата нет.

Настройки accounting:

Код:

            <param name="recvBufferSize">1 * 1024 * 1024</param>
            <param name="soRCVBUF"></param>
            <param name="threadCount">14</param>
            <param name="maxQueueSize">200</param>
            <param name="processor">radiusProcessor</param>
            <param name="mode">RadiusListener.Mode.accounting</param>
            <param name="setup">setup</param>
            <param name="dataLogger">radiusDataLogger</param>

Собственно тупо всё скопированно со старого сервера, только threadCount там было = 10, и хватало.
Пробовал менять количество потоков уменьшал/добавлял, увеличивал немного очередь, ни каких
существенных эффектов нет. При уменьшении количества потоков всё же снижалось
количество "MySQL Statement Cancellation Timer" в сообщении до 8-9, вместо 14-16
(но вот это не очень достоверно, требуется понаблюдать бы несколько дней).

Конфиг access+accounting:

Код:

accounting.worker.1.thread.count=2
accounting.worker.1.tariffication.1.minDeltaAmount=0
accounting.worker.1.tariffication.1.delay=10
accounting.worker.1.tariffication.1.batchSize=1000
accounting.worker.1.tracking.1.delay=10
accounting.worker.1.tracking.1.batchSize=1000
accounting.worker.1.serv.tracking.1.delay=20
accounting.worker.1.serv.tracking.1.batchSize=100
 
accounting.worker.2.thread.count=1
accounting.worker.2.flushing.1.minDeltaAccount=0
accounting.worker.2.flushing.1.minDeltaAmount=0
accounting.worker.2.flushing.1.delay=20
accounting.worker.2.flushing.1.batchSize=500
 
accounting.worker.3.thread.count=1
accounting.worker.3.finishing.1.delay=20
accounting.worker.3.finishing.1.batchSize=500

таких устройств (aaa) в дереве соответственно два (PPP и IPoE).
На серваке тоже крутятся соответственно две пары access+accounting сервисов.
Сообщение шлёт accounting ppp, на него собственно вся нагрузка,
на данный момент порядка 1200 соединений, а планируется туда влить ещё порядка 9000 коннектов
(вот тут мне как-то страшно становится).
Самое смешное, что всё тот же комплект сервисов крутился до этого в виртуалке, на всё отдано было
два ядра и 3Гига памяти. Оно даже в консоли чувствовалось, что маловато ресурсов, по отклику.
Но, ни каких таких проблем не было.

Прошу совета куда посмотреть, что покрутить чтоб разобраться с проблемой.

Вложения:

errmsg.txt [64.89 КБ]
Скачиваний: 467

_________________
Клиент: вер. 7.1.206 / 15.08.2019 22:37:24
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_181
Сервер: вер. 7.1.1144 / 15.08.2019 22:39:22
os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_181

Вернуться к началу

fmaks

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 29 авг 2017, 17:07

Зарегистрирован: 20 окт 2016, 00:34
Сообщения: 82
Карма: 0

inet: вер. 7.0.770 / 16.08.2017 12:30:12

Вернуться к началу

Amir

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 29 авг 2017, 21:14

Разработчик

Зарегистрирован: 19 дек 2006, 21:04
Сообщения: 5970
Карма: 256

А что в top при этом? Виртуалка была на другой машине, т.е. жесткий диск там был другой?

Попробуйте указать в my.cnf
innodb_flush_log_at_trx_commit=2

Вернуться к началу

fmaks

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 30 авг 2017, 01:59

Зарегистрирован: 20 окт 2016, 00:34
Сообщения: 82
Карма: 0

Да, виртуалка была в xen-кластере, сейчас это выделеный сервер,
естественно всё железо другое.

innodb_flush_log_at_trx_commit=2 - давно указано, собственно настройка практически по wiki.
Сегодня чуть покрутил buffer_pool_instances, посмотрю что будет.

Вернуться к началу

fmaks

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 30 авг 2017, 02:30

Зарегистрирован: 20 окт 2016, 00:34
Сообщения: 82
Карма: 0

Сегодня письмо счастья не пришло.
Собственно:
- подрезал БД до 132Гб;

добавил
- innodb_buffer_pool_instances = 8
судя по доке при innodb_buffer_pool_size > 1G лучше делать несколько инстансов,
как раз влияет на конкуретный доступ;

в inet-accounting.xml поставил:
<param name="threadCount">32</param>
<param name="maxQueueSize">200</param>

Не знаю что из это повлияло.

В топе в 00:00 на сервере с accesss+accounting практически ни чего,
на мгновение прыгнула нагрузка на процессор и всё.
На сервере бд тоже самое, чуть выросла нагрузка на одном ядре
и подрос wait на одном ядре до 5-6% на 1-2 секунды и всё.

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

Вернуться к началу

ok-2004

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 30 авг 2017, 16:46

Клиент

Зарегистрирован: 21 май 2008, 10:54
Сообщения: 599
Откуда: 50-й рег.
Карма: 40

Хе-хе... Старые грабли о главном...

1. innodb_flush_log_at_trx_commit = 2 - хорошо для небольшого интернет-магазина, но не как не для базы БЖБ, которая работает в huge OLTP.
Например у меня за секунду в базу прилетает :

Код:

Com_select : 217.58333
Com_insert : 70.41666
Com_delete : 66.83333
Com_update : 206.91666
Com_replace : 0.00000
Com_commit : 29.16666
Queries : 674.25000
Questions : 603.75000
Innodb_data_writes : 22.41666
Innodb_data_written : 73557.33333

при значении "2" в случае чего я бы потерял :

Код:

Com_insert : 70.41666
Com_delete : 66.83333
Com_update : 206.91666
Com_commit : 29.16666

Какой же это ACID-compliant ?
Ставьте только "1" ! Да плюс к тому и "innodb_doublewrite = ON" влепите и будете спать спокойно.

2. "innodb_buffer_pool_instances = 8" логично если у Вас число настоящих ядер ЦПУ= 8 и "innodb_buffer_pool_size" не меньше половины РАМ.
Если винты медленные - добавьте
"innodb_page_cleaners = 8
innodb_lru_scan_depth=256"
иначе получите
"InnoDB: page_cleaner: 1000ms intended loop took 16924ms. The settings might not be optimal. (flushed=404, during the time.)" в mysql_error.log

ЗЫ: а вообще все эти Ваши ошибки по большому - следствие медленных винтов.
Запустите вечерком
pt-diskstats --columns-regex='rd_s|rd_mb_s|rd_rt|wr_s|wr_mb_s|wr_rt|busy' --devices-regex='sda|sdb' --interval=10 --iterations=100
и понаблюдайте.
А на сон грядущий прочтите :
https://www.percona.com/blog/2017/08/28 ... aturation/

_________________
"Все правые - в резерве!" (c) (translate.google.ru/#en/ru/all%20rigths%20reserved)

Вернуться к началу

Amir

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 30 авг 2017, 19:18

Разработчик

Зарегистрирован: 19 дек 2006, 21:04
Сообщения: 5970
Карма: 256

Да, innodb_flush_log_at_trx_commit=2 по сути - решение проблем с медленной дисковой подсистемой.
Просто часто сталкиваемся, что пишут, что биллинг тормозит, а на тесте оказывается, что диск выполняет очень мало sync в секунду (например, меньше чем на моем рабочем WD Green).

Вернуться к началу

fmaks

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 30 авг 2017, 20:01

Зарегистрирован: 20 окт 2016, 00:34
Сообщения: 82
Карма: 0

Согласен про innodb_flush_log_at_trx_commit=2.
Но, пока согласен на такой риск.
+------------+-------------+------
| query_type | per_second |
+------------+-------------+------
| COMMIT | 254.91
| DELETE | 0.68
| INSERT | 9.18
| SELECT | 187.97
| UPDATE | 249.73
+------------+-------------+------
На сколько я понимаю, вслучае падения оси, либо железа/питания
при innodb_flush_log_at_trx_commit=1 можно потерять последнюю транзакцию,
при innodb_flush_log_at_trx_commit=2 можно потерять транзакции приблизительно за секунду.
В конце-концов BBU + резервное питание и uptime 1528 days.

Но согласен, нужно innodb_flush_log_at_trx_commit=1, но это нужно тестировать и явно не на боевом серваке.

Цитата:

"innodb_buffer_pool_instances = 8" логично если у Вас число настоящих ядер ЦПУ= 8 и "innodb_buffer_pool_size" не меньше половины РАМ.

С ядрами и памятью там всё более менее нормально.
Меня больше смущает как он делит инстансы
при
innodb_buffer_pool_size=24G
innodb_buffer_pool_instances = 8
получаем 8 инстансов по 2G, эм... даже с учетом накладных расходов на каждый буфер, не совсем понятно :-)

Цитата:

https://www.percona.com/blog/2017/08/28 ... aturation/

Спасибо, определенно дочитаю.

pt-diskstats - из percon-ы у нас дремучий 5.5,
тащить репы и зависимости на боевой сервак как-то напрягает.
sysbench - аналогично, при чём тянет аж postgresql-libs.

Код:

Linux 2.6.32-358.11.1.el6.x86_64 (mysql.xxxx.ru)    30.08.2017    _x86_64_   (24 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0,31    0,00    0,11    0,02    0,00   99,56

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda              49,38    23,77    2,88   30,36   435,82   754,50    35,81     0,01    0,40    2,41    0,21   0,13   0,43

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0,13    0,00    0,13    0,00    0,00   99,75

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0,00    12,00    0,00   78,00     0,00  1416,00    18,15     0,01    0,09    0,00    0,09   0,06   0,50

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0,08    0,00    0,08    0,00    0,00   99,83

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0,00     7,00    0,00   80,00     0,00  1336,00    16,70     0,01    0,09    0,00    0,09   0,06   0,50

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0,13    0,00    0,13    0,00    0,00   99,75

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0,00    13,00    0,00  184,00     0,00  3560,00    19,35     0,01    0,07    0,00    0,07   0,04   0,80

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0,21    0,00    0,08    0,00    0,00   99,71

Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0,00    13,00    0,00   93,00     0,00  1488,00    16,00     0,01    0,09    0,00    0,09   0,05   0,50

опять же не вижу ни какого особого криминала, да, это не SSD.
Буду мониторить и ожидать писем счастья.

Вернуться к началу

Amir

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 30 авг 2017, 20:21

Разработчик

Зарегистрирован: 19 дек 2006, 21:04
Сообщения: 5970
Карма: 256

Еще может быть такая ситуация, что cisco шлет аккаунтинг не более менее распределенно, а выплевывает сразу по многим сессиям одновременно.
Получается, что биллингу сваливается в один момент времени много пакетов, которые он пытается обработать. А на переходе дня - сплитить сессии.
Например, 1000 пакетов, а очередь - 200, тогда биллинг ругается.

Очередь можно было бы увеличить, но тут возможна ситуация, что к тому времени как пакет будет обработан, NAS решит,
что прошел таймаут и пошлет новый пакет - получится что биллинг будет обрабатывать одни и теже пакеты по несколько раз, что не уменьшит нагрузку.
Думаю, с увеличением очереди нужно увеличивать таймаут RADIUS-запросов в NAS.

Вернуться к началу

fmaks

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 30 авг 2017, 21:24

Зарегистрирован: 20 окт 2016, 00:34
Сообщения: 82
Карма: 0

Цитата:

Возможно, но тогда уж много совпадений несколько дней подряд, хотя всякое может быть.
Но, вчера снимали за минуту RADIUS accounting tcpdump-ом, подобного не заметили,
хотя, может не та минута была :-)

И да, у меня тогда вопрос - а как считается, сколько сервис может выдержать пакетов "за раз",
я считал типа threadCount*maxQueueSize, т.е. у нас есть пул из X потоков готовый обрабатывать соединения
и каждый из пулов имеет очередь maxQueueSize, а получается есть разделяемый пул из которого пачка потоков
вытаскивает задачи? При этом нежелательно, чтобы очередь была длиннее 200 RADIUS пакетов (было где-то на форуме)?
Правильно?

Цитата:

Очередь можно было бы увеличить, но тут возможна ситуация, что к тому времени как пакет будет обработан, NAS решит,
что прошел таймаут и пошлет новый пакет - получится что биллинг будет обрабатывать одни и теже пакеты по несколько раз, что не уменьшит нагрузку.

Это понятно, но странно, дефолтный таймаут для RADIUS-пакета на cisco 5 сек, это очень много, на мой взгляд, времени для обработки.
Да и собственно количество Accounting-Request/Reply практически совпадает за минуту (tcpdump), т.е. отвечать то в обычное время успевает.
Вот что там на границе суток происходит когда логически завершаются все сессии, это было бы интересно посмотреть.

Вернуться к началу

fmaks

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 30 авг 2017, 21:33

Зарегистрирован: 20 окт 2016, 00:34
Сообщения: 82
Карма: 0

Есть у меня подозрения, что письма начали приходить когда база переросла где-то 150 Гигов,
но для того чтобы это как-то подтвердить или опровергнуть придётся ждать.
К сожалению маловато инфы в Инете по поводу баз MySQL больше сотни гигов, всё больше
общие слова про оптимизацию. Стоит ли держать такую базу или лучше её постоянно подрезать
(не хотелось бы на самом деле)?
Это опять же если проблема в ней.

Вернуться к началу

ok-2004

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 31 авг 2017, 01:33

Клиент

Зарегистрирован: 21 май 2008, 10:54
Сообщения: 599
Откуда: 50-й рег.
Карма: 40

Здесь всё очень просто..
Большая таблица ( точнее таблица с большим числом строк ) - для мускула , как и для любого движка баз данных. хранящего индесы с одном файле с данными - смерть лютая и никакими подкручиваниями переменных сервера здесь проблему не решить.
Это для Myisam индексы и данные хранились в разных файлах и именнно select вместе с join в таблице Myisam с миллионом строк был на порядок быстрее чем для innodb.
Самое печальное , что кэш индесов спасает только для insert/delete/update, которые топчатся в одном диапазоне строк таблицы.
В случае select/join в 50 процентах случаев Вы получите кэш misses и отправитесь за ними в файл таблицы, в котором данные занимают только половину, остальное - отсортированные по индексам номера строк.
Некоторые страдальцы советуют по максимуму выкручивать буфера/кэши, дабы загнать почти всю базу в RAM и по максимуму увеличивать число тредов, опорожняющих их.
Я выбрал для себя золотую середину - 50 процентов РАМ-а. У меня памяти 32 гига , половину отдал под буффер-пул.
значит моя база должна быть не больше 30 гигов. Поэтому раз в полгода в течении 8 лет я её обрезаю до 30 гигов и никаких криминалов пока не замечал...

_________________
"Все правые - в резерве!" (c) (translate.google.ru/#en/ru/all%20rigths%20reserved)

Вернуться к началу

fmaks

Заголовок сообщения: Re: accounting queue is full на границе суток

Добавлено: 31 авг 2017, 18:35

Зарегистрирован: 20 окт 2016, 00:34
Сообщения: 82
Карма: 0

Всё-таки будем надеяться что кэш на то и кэш, что в него должны попадать "горячие данные".
Мало вероятно, что у меня их прям огромное количество, большую часть всё-таки занимают историчные таблицы,
У меня так же 32 и по mysql-ной доке отдано под буфер 24Гб.
Можно сказать что база до 100Гигов не проявляет ни каких тормозов в реальной каждодневной работе.
Опят же, у нас может быть разная нагрузка.
Вот думаю в течении месяца я нагружу её повеселее перелив ещё приличное количество абонентов в БГ,
тогда и будет видно. Пока, после последних манипуляций, письма не приходят, ошибка не выпадает.
Буду наблюдать.

Вернуться к началу

Страница 1 из 1

[ Сообщений: 13 ]

Список форумов » BGBilling » Модули Интернета » Модуль Inet

Часовой пояс: UTC + 5 часов [ Летнее время ]

Кто сейчас на конференции

Сейчас этот форум просматривают: нет зарегистрированных пользователей и гости: 1

Вы не можете начинать темы
Вы не можете отвечать на сообщения
Вы не можете редактировать свои сообщения
Вы не можете удалять свои сообщения
Вы не можете добавлять вложения

Перейти:

BiTel

accounting queue is full на границе суток

Кто сейчас на конференции