forum.bitel.ru :: Просмотр темы - Ошибка в InetAccounting после обновления 7.0 -> 7.1

05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] ISGProtocolHandler2 - PARENT_ACCOUNTING_SESSION_ID: 0/0/0/2515_0A260A010136C2F8 radiusVendor:9 parentAcctSessionIdType:1 prefix:parent-session-id=
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] ISGProtocolHandler2 - PARENT_ACCOUNTING_SESSION_ID: null radiusVendor:9 parentAcctSessionIdType:1 prefix:parent-session-id=
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] ISGProtocolHandler2 - SERVICE NAME: NISG-IPoE-INTERNET
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] ISGProtocolHandler2 - DISABLE SERVICE NAMES: [RDR-IPOE-SERVICE, TRUST-IPOE-SERVICE]
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS:
Packet type: Accounting-Request
Identifier: 174
Authenticator: {8D E3 17 70 35 D4 18 59 8F 6E 70 E0 D2 B6 67 B0}
Attributes:
NAS-Identifier=ASR-01.Metromax.ru
User-Name=81.200.xxx.33
NAS-IP-Address=10.63.7.250
NAS-Port=20366072
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=81.200.xxx.33
Acct-Status-Type=1
Acct-Delay-Time=0
Acct-Session-Id=0/0/0/2515_0A260A010136C2F8
Acct-Authentic=2
NAS-Port-Id=0/0/0/2515
Event-Timestamp=1557823131
NAS-Port-Type=33
cisco-avpair=connect-progress=Call Up
cisco-NAS-Port=0/0/0/2515
cisco-SSG-Service-Info=NISG-IPoE-INTERNET
cisco-SSG-Control-Info=I0;0
cisco-SSG-Control-Info=O0;0

05-14/12:38:51 INFO [rdsLstnr-p-8-t-8] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS:
Packet type: Accounting-Request
Identifier: 175
Authenticator: {D6 1D 6B 34 F6 BD 37 D4 76 FC 1C 46 C1 AF 7C CE}
Attributes:
NAS-Identifier=ASR-01.Metromax.ru
User-Name=81.200.xxx.33
NAS-IP-Address=10.63.7.250
NAS-Port=20366072
Service-Type=2
Framed-Protocol=1
Acct-Status-Type=1
Framed-IP-Address=81.200.xxx.33
Acct-Delay-Time=0
Acct-Session-Id=0/0/0/2515_0A260A010136C2F9
NAS-Port-Id=0/0/0/2515
Event-Timestamp=1557823131
NAS-Port-Type=33
cisco-avpair=parent-session-id=0/0/0/2515_0A260A010136C2F8
cisco-NAS-Port=0/0/0/2515
cisco-SSG-Service-Info=NISG-IPoE-INTERNET
Common options: {parentAcctSessionId=0/0/0/2515_0A260A010136C2F8, deviceState=null, serviceName=ISG-IPoE-INTERNET}
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] InetRadiusProcessor - Option parentAcctSessionId is set but connection not found with acctSessionId=0/0/0/2515_0A260A010136C2F8. Add to start with$
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetNas - Search by address=81.200.xxx.33
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] ProcessorRequest - Sending to /10.63.7.250:1646
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetRadiusProcessor - Creating NasConnection from radius accounting packet
05-14/12:38:51 INFO [rdsLstnr-p-8-t-8] RadiusListenerWorker - RESPONSE:
Packet type: Accounting-Response
Identifier: 175
Authenticator: {9D F3 6A 69 CA AA D6 7C 3C 2F 1E F2 1F 53 48 59}
Attributes:

Process time start: 1

05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetRadiusProcessor - Connection exist in DB
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] InetNas - agentRemoteId=null
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] InetRadiusProcessor - ipResourceId=15
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] Accounting - Update connection in DB
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] Accounting - Write new session to DB
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] Accounting - New session's id=34443166
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] Accounting - Created new AccountingSession.
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] Accounting - Register 81.200.xxx.32 on 12:-1
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] connection - 29158955:34443166 Register ip: 81.200.xxx.33
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetConnectionKeyMap - Put connection add 0000.0000.0000
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] Accounting - InetConnection [id=29158955-0, iface=12:20366072, sessId=0/0/0/2515_0A260A010136C2F8, start=14.05.2019 12:38:51, uname=81.200.xxx.33,$
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] InetNas - Start service connection
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetRadiusProcessor - Creating NasConnection from radius accounting packet
05-14/12:38:51 ERROR [rdsLstnr-p-8-t-6] RadiusListenerWorker -
java.lang.NullPointerException
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnectionFromServ(InetRadiusProcessor.java:1929)
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1807)
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1680)
at ru.bitel.bgbilling.modules.inet.radius.InetNas.startWithParentProcess(InetNas.java:1517)
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnectionFromServ(InetRadiusProcessor.java:2230)
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1807)
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1680)
at ru.bitel.bgbilling.modules.inet.radius.InetNas.startConnection(InetNas.java:667)
at ru.bitel.bgbilling.modules.inet.radius.InetNas.startConnection(InetNas.java:76)
at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accounting(RadiusProcessor.java:663)
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusHelperProcessor.accounting(InetRadiusHelperProcessor.java:144)
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusHelperProcessor.accounting(InetRadiusHelperProcessor.java:32)
at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accountingRequest(RadiusProcessor.java:594)
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accountingRequest(InetRadiusListenerWorker.java:212)
at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accountingRequest(InetRadiusListenerWorker.java:36)
at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.processAccountingRequest(RadiusListenerWorker.java:351)
at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.processPacket(RadiusListenerWorker.java:322)
at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.runImpl(RadiusListenerWorker.java:150)
at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:87)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46)
05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] ProcessorRequest - Sending to /10.63.7.250:1646
05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] RadiusListenerWorker - RESPONSE:
Packet type: Accounting-Response
Identifier: 174
Authenticator: {43 D8 4B 18 6E 13 37 16 A7 60 5A A7 E7 7B 9C CC}
Attributes:

Process time start: 9

Автор:	fmaks [ 10 май 2019, 12:06 ]
Заголовок сообщения:	Ошибка в InetAccounting после обновления 7.0 -> 7.1
Добрый день. После обновления 7.0 -> 7.1 в логе InetAccounting error.log сыпятся ошибки: Код: radius 05-10/09:09:49 ERROR [rdsLstnr-p-8-t-57] RadiusListenerWorker - java.lang.NullPointerException at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnectionFromServ(InetRadiusProcessor.java:1929) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1807) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1680) at ru.bitel.bgbilling.modules.inet.radius.InetNas.startWithParentProcess(InetNas.java:1517) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnectionFromServ(InetRadiusProcessor.java:2230) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1807) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1680) at ru.bitel.bgbilling.modules.inet.radius.InetNas.startConnection(InetNas.java:667) at ru.bitel.bgbilling.modules.inet.radius.InetNas.startConnection(InetNas.java:76) at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accounting(RadiusProcessor.java:663) at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accountingRequest(RadiusProcessor.java:594) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accountingRequest(InetRadiusListenerWorker.java:212) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accountingRequest(InetRadiusListenerWorker.java:36) at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.processAccountingRequest(RadiusListenerWorker.java:351) at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.processPacket(RadiusListenerWorker.java:322) at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.runImpl(RadiusListenerWorker.java:150) at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:87) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46) и вроде как и сессии есть, и аккаунтинг считается, и сессии дропаются, но вот это как-то совсем не хорошо. При чём судя по всему интенсивность возникновения ошибок растёт. + Например, у абонента pppoe со стратикой наблюдаю в connection.log Register ip: xxx.xxx.xxx.xxx пачкой Потом Unregister ip: xxx.xxx.xxx.xxx тоже пачкой, итог - туча сессий в состоянии закрыт - подключен. Подскажите куда копать? Сервер: вер. 7.1.1119 / 25.04.2019 13:59:06 os: Linux; java: Java HotSpot(TM) 64-Bit Server VM, v.1.8.0_181 inet: вер. 7.1.703 / 08.05.2019 09:40:27

Автор:	fmaks [ 14 май 2019, 16:04 ]
Заголовок сообщения:	Re: Ошибка в InetAccounting после обновления 7.0 -> 7.1
Апну тему, т.к. ошибки ни куда не исчазли. Была мысль, что просто какие-то сессии подвисли за время обновления, но похоже нет. Включил отладку но сильно это не помогает. Вроде отловил следующее в логе IPoE (т.к. там просто меньше абонентов и ошибки значительно реже): Код: 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] ISGProtocolHandler2 - PARENT_ACCOUNTING_SESSION_ID: 0/0/0/2515_0A260A010136C2F8 radiusVendor:9 parentAcctSessionIdType:1 prefix:parent-session-id= 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] ISGProtocolHandler2 - PARENT_ACCOUNTING_SESSION_ID: null radiusVendor:9 parentAcctSessionIdType:1 prefix:parent-session-id= 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] ISGProtocolHandler2 - SERVICE NAME: NISG-IPoE-INTERNET 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] ISGProtocolHandler2 - DISABLE SERVICE NAMES: [RDR-IPOE-SERVICE, TRUST-IPOE-SERVICE] 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS: Packet type: Accounting-Request Identifier: 174 Authenticator: {8D E3 17 70 35 D4 18 59 8F 6E 70 E0 D2 B6 67 B0} Attributes: NAS-Identifier=ASR-01.Metromax.ru User-Name=81.200.xxx.33 NAS-IP-Address=10.63.7.250 NAS-Port=20366072 Service-Type=2 Framed-Protocol=1 Framed-IP-Address=81.200.xxx.33 Acct-Status-Type=1 Acct-Delay-Time=0 Acct-Session-Id=0/0/0/2515_0A260A010136C2F8 Acct-Authentic=2 NAS-Port-Id=0/0/0/2515 Event-Timestamp=1557823131 NAS-Port-Type=33 cisco-avpair=connect-progress=Call Up cisco-NAS-Port=0/0/0/2515 cisco-SSG-Service-Info=NISG-IPoE-INTERNET cisco-SSG-Control-Info=I0;0 cisco-SSG-Control-Info=O0;0 05-14/12:38:51 INFO [rdsLstnr-p-8-t-8] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS: Packet type: Accounting-Request Identifier: 175 Authenticator: {D6 1D 6B 34 F6 BD 37 D4 76 FC 1C 46 C1 AF 7C CE} Attributes: NAS-Identifier=ASR-01.Metromax.ru User-Name=81.200.xxx.33 NAS-IP-Address=10.63.7.250 NAS-Port=20366072 Service-Type=2 Framed-Protocol=1 Acct-Status-Type=1 Framed-IP-Address=81.200.xxx.33 Acct-Delay-Time=0 Acct-Session-Id=0/0/0/2515_0A260A010136C2F9 NAS-Port-Id=0/0/0/2515 Event-Timestamp=1557823131 NAS-Port-Type=33 cisco-avpair=parent-session-id=0/0/0/2515_0A260A010136C2F8 cisco-NAS-Port=0/0/0/2515 cisco-SSG-Service-Info=NISG-IPoE-INTERNET Common options: {parentAcctSessionId=0/0/0/2515_0A260A010136C2F8, deviceState=null, serviceName=ISG-IPoE-INTERNET} 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] InetRadiusProcessor - Option parentAcctSessionId is set but connection not found with acctSessionId=0/0/0/2515_0A260A010136C2F8. Add to start with$ 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetNas - Search by address=81.200.xxx.33 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-8] ProcessorRequest - Sending to /10.63.7.250:1646 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetRadiusProcessor - Creating NasConnection from radius accounting packet 05-14/12:38:51 INFO [rdsLstnr-p-8-t-8] RadiusListenerWorker - RESPONSE: Packet type: Accounting-Response Identifier: 175 Authenticator: {9D F3 6A 69 CA AA D6 7C 3C 2F 1E F2 1F 53 48 59} Attributes: Process time start: 1 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetRadiusProcessor - Connection exist in DB 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] InetNas - agentRemoteId=null 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] InetRadiusProcessor - ipResourceId=15 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] Accounting - Update connection in DB 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] Accounting - Write new session to DB 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] Accounting - New session's id=34443166 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] Accounting - Created new AccountingSession. 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] Accounting - Register 81.200.xxx.32 on 12:-1 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] connection - 29158955:34443166 Register ip: 81.200.xxx.33 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetConnectionKeyMap - Put connection add 0000.0000.0000 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] Accounting - InetConnection [id=29158955-0, iface=12:20366072, sessId=0/0/0/2515_0A260A010136C2F8, start=14.05.2019 12:38:51, uname=81.200.xxx.33,$ 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] InetNas - Start service connection 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] InetRadiusProcessor - Creating NasConnection from radius accounting packet 05-14/12:38:51 ERROR [rdsLstnr-p-8-t-6] RadiusListenerWorker - java.lang.NullPointerException at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnectionFromServ(InetRadiusProcessor.java:1929) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1807) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1680) at ru.bitel.bgbilling.modules.inet.radius.InetNas.startWithParentProcess(InetNas.java:1517) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnectionFromServ(InetRadiusProcessor.java:2230) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1807) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusProcessor.getNasConnection(InetRadiusProcessor.java:1680) at ru.bitel.bgbilling.modules.inet.radius.InetNas.startConnection(InetNas.java:667) at ru.bitel.bgbilling.modules.inet.radius.InetNas.startConnection(InetNas.java:76) at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accounting(RadiusProcessor.java:663) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusHelperProcessor.accounting(InetRadiusHelperProcessor.java:144) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusHelperProcessor.accounting(InetRadiusHelperProcessor.java:32) at ru.bitel.bgbilling.kernel.network.radius.RadiusProcessor.accountingRequest(RadiusProcessor.java:594) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accountingRequest(InetRadiusListenerWorker.java:212) at ru.bitel.bgbilling.modules.inet.radius.InetRadiusListenerWorker.accountingRequest(InetRadiusListenerWorker.java:36) at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.processAccountingRequest(RadiusListenerWorker.java:351) at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.processPacket(RadiusListenerWorker.java:322) at ru.bitel.bgbilling.kernel.network.radius.RadiusListenerWorker.runImpl(RadiusListenerWorker.java:150) at ru.bitel.common.worker.WorkerTask.run(WorkerTask.java:87) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) at ru.bitel.common.worker.WorkerThread.run(WorkerThread.java:46) 05-14/12:38:51 DEBUG [rdsLstnr-p-8-t-6] ProcessorRequest - Sending to /10.63.7.250:1646 05-14/12:38:51 INFO [rdsLstnr-p-8-t-6] RadiusListenerWorker - RESPONSE: Packet type: Accounting-Response Identifier: 174 Authenticator: {43 D8 4B 18 6E 13 37 16 A7 60 5A A7 E7 7B 9C CC} Attributes: Process time start: 9 В логе сессий на клиенте видно что сессия закончилась в пределах данного времени и началась новая. Уважаемые разработчики, подскажите что может являться причиной ошибки. Нужны ли какие-то доп. логи, конфиг? inet: вер. 7.1.703 / 08.05.2019 09:40:27

Автор:	Amir [ 20 май 2019, 18:23 ]
Заголовок сообщения:	Re: Ошибка в InetAccounting после обновления 7.0 -> 7.1
Выложили обновление

Автор:	fmaks [ 21 май 2019, 12:39 ]
Заголовок сообщения:	Re: Ошибка в InetAccounting после обновления 7.0 -> 7.1
Спасибо. Запланировали обновление, по результатам отпишусь.

forum.bitel.ru http://forum.bitel.ru/

Ошибка в InetAccounting после обновления 7.0 -> 7.1 http://forum.bitel.ru/viewtopic.php?f=44&t=13331	Страница 1 из 1

Страница 1 из 1	Часовой пояс: UTC + 5 часов [ Летнее время ]
Powered by phpBB® Forum Software © phpBB Group http://www.phpbb.com/