forum.bitel.ru :: Просмотр темы - [5.2] InetAccounting - Reject-to-Accept

connection 03-06/10:37:13 DEBUG [sa-p-9-t-4] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateM
odifyEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 5; inetServId: 11; connectionId: 6221; state: 0; accessCode: 10; timestamp: 133
1023033068
connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Do task deviceId: 5; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSa
StateModifyEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 5; inetServId: 11; connectionId: 6221; state: 0; accessCode: 10; timestam
p: 1331023033068
connection 03-06/10:37:13 INFO [sa-p-9-t-4] InetApplication - TariffOptionMap: {}
connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 11; call: true; o
ldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1
connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Processing deviceId:5; command ServiceActivatorEvent type=2; inetServId: 11; call
: true; oldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1
connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorSet - Invoking connectionModify
connection 03-06/10:37:13 INFO [sa-p-9-t-4] MTCoAServiceActivator - Connection modify: oldState: 1; newState: 0; oldOptionSet: [1]; newOptionSet: [1]
connection 03-06/10:37:13 INFO [sa-p-9-t-4] MTCoAServiceActivator - Connection close
connection 03-06/10:37:13 INFO [sa-p-9-t-4] MTCoAServiceActivator - Send PoD:
Packet type: Disconnect-Request
Identifier: 29
Authenticator: {7D 92 9B 3F FA A8 AA C2 FC 5A A9 FF 70 2D D0 EB}
Attributes:
User-Name=bg@localhost
Framed-IP-Address=X.206.252.182

connection 03-06/10:37:13 INFO [sa-p-9-t-4] RadiusClient - Sending to /192.168.1.250:1700
Packet type: Disconnect-Request
Identifier: 29
Authenticator: {7D 92 9B 3F FA A8 AA C2 FC 5A A9 FF 70 2D D0 EB}
Attributes:
User-Name=bg@localhost
Framed-IP-Address=X.206.252.182

connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Process event type[2] result=true
connection 03-06/10:37:13 INFO [pod-support-p1700] RadiusClient - Recieved from /192.168.1.250:1700
Packet type: Disconnect-ACK
Identifier: 29
Authenticator: {9B 03 B6 09 B9 61 5F 08 92 87 CF 90 E3 EF A0 7A}
Attributes:
NAS-Identifier=pt
NAS-IP-Address=192.168.1.250

connection 03-06/10:37:13 DEBUG [sa-p-9-t-4] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccoun
tingEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 5; connectionId: 6221; timestamp: 1331023033086
connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Do task deviceId: 5; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSa
AccountingEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 5; connectionId: 6221; timestamp: 1331023033086
connection 03-06/10:37:13 INFO [sa-p-9-t-4] InetApplication - TariffOptionMap: {}
connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=5; inetServId: 11; call: true; o
ldState: 0; newState: 0; oldOptionSet: 1; newOptionSet: 1
connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Processing deviceId:5; command ServiceActivatorEvent type=5; inetServId: 11; call
: true; oldState: 0; newState: 0; oldOptionSet: 1; newOptionSet: 1
connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorSet - Invoking onAccountingStop
connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Process event type[5] result=true
mq 03-06/10:37:13 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] m
oduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 5; connectionId: 6221; timestamp: 1331023033086
mq 03-06/10:37:13 INFO [event-proc-p-2-t-1] InetConnectionManager - Remove connection: InetConnection [id=6221-0, iface=5:370451, sessId=81f07c65, start=06.
03.2012 10:35:59, uname=bg@localhost, addr=91.206.252.182]
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] RadiusListenerWorker - REQUEST:
Packet type: Access-Request
Identifier: 217
Authenticator: {CC EC F0 74 6E 20 20 6F CC 7B AD 57 55 AA EF 55}
Attributes:
User-Name=bg@localhost
NAS-Identifier=pt
NAS-IP-Address=192.168.1.250
NAS-Port=370452
Service-Type=2
Framed-Protocol=1
Calling-Station-Id=192.168.1.174
NAS-Port-Type=5
Called-Station-Id=192.168.1.250
Mikrotik-Realm=localhost
MS-CHAP2-Response={01 00 B6 49 B5 FF 17 8F A3 74 DD C9 21 C2 85 4B 28 B1 00 00 00 00 00 00 00 00 25 DE E7 44 3C 7C EC 20 3E 2A EC 41 F0 CF E8 F7 38 2C A3 D
C 8F 12 38 50}
MS-CHAP-Domain=localhost
MS-CHAP-Challenge={20 58 E2 66 65 14 7D 70 79 D3 23 32 CD 6A B5 59}

radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusProcessor - Create new radius session.
radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - try checkDigestMD5Password
radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - digestAttributes=null
radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - digestResponse=null
radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - user =null realm =null nonce = null method = null uri = null
radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - try all in one string
radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - digestAttribute=null
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusProcessor - [username=bg] Authenticated as inetServId:11
radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] InetRadiusProcessor - MAC-address from request:
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Access - inetServ[id=11] deviceState not active (accessCode=44).
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusProcessor - Return code=0
radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] ProcessorRequest - Sending to /192.168.1.250:34989
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusListenerWorker - RESPONSE:
Packet type: Access-Accept
Identifier: 217
Authenticator: {CA 6F 0F 17 83 99 26 CF 14 3B C5 BC 22 54 CB F4}
Attributes:
Framed-IP-Address=192.168.66.60
Mikrotik-Address-List=INET_DISABLED
MS-MPPE-Recv-Key={93 59 22 20 17 1C 47 03 E0 22 2D DA 3B 75 51 B0 B5 9C D9 2F E3 72 12 64 14 7D 89 FF EB EE 60 6F 31 52}
MS-MPPE-Send-Key={ED 13 D2 A0 29 0A 55 56 0F 97 D1 4C 8D 41 9D 5B 81 EE BA B7 BB F6 AE C0 F2 A5 AB 1A 2A 3C A1 7B 72 6A}
MS-CHAP2-Success={3F 53 3D 36 46 35 39 46 34 43 31 32 39 44 43 36 42 35 42 39 35 31 43 43 38 37 39 33 45 34 45 45 41 44 39 41 42 39 36 36 36 31 43}

Process time auth: 6

accounting 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] InetApplication - TariffOptionMap: {}
accounting 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 inetServ[id=11] not active.
accounting 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Found error 10
accounting 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Sending event to stop session...
radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] RadiusListenerWorker - REQUEST:
Packet type: Accounting-Request
Identifier: 216
Authenticator: {AD 88 87 20 59 DC 66 6E FC C4 3E FD CA DD DF 3A}
Attributes:
User-Name=bg@localhost
NAS-Identifier=pt
NAS-IP-Address=192.168.1.250
NAS-Port=370451
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=X.206.252.182
Acct-Input-Octets=74
Acct-Output-Octets=70
Acct-Status-Type=2
Acct-Delay-Time=0
Acct-Session-Time=76
Acct-Input-Packets=8
Acct-Session-Id=81f07c65
Acct-Authentic=1
Acct-Terminate-Cause=10
Acct-Output-Packets=7
Event-Timestamp=1331023033
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=192.168.1.174
Called-Station-Id=192.168.1.250
Mikrotik-Realm=localhost
MS-CHAP-Domain=localhost
radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] InetRadiusProcessor - Session 81f07c65 found.
radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] InetNas - Stopping NasConnection
radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] connection - 6221:6465 Stopping NasConnection
radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] InetConnectionRuntime - Stopping connection with id=6221

radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] RadiusListenerWorker - RESPONSE:
Packet type: Accounting-Response
Identifier: 216
Authenticator: {DE 9F 34 38 C9 F3 74 74 4B 3A 37 B8 0C 2C BB 92}
Attributes:

Process time stop: 12

accounting 03-06/10:37:16 INFO [accwrkr-1-p-12-t-1] InetApplication - TariffOptionMap: {}
accounting 03-06/10:37:16 INFO [accwrkr-1-p-12-t-1] InetApplication - TariffOptionMap: {}
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] RadiusListenerWorker - REQUEST:
Packet type: Accounting-Request
Identifier: 218
Authenticator: {B3 D3 20 E1 D4 53 2C E2 D2 19 0C A0 4E 68 70 A6}
Attributes:
User-Name=bg@localhost
NAS-Identifier=pt
NAS-IP-Address=192.168.1.250
NAS-Port=370452
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=192.168.66.60
Acct-Status-Type=1
Acct-Delay-Time=0
Acct-Session-Id=81f07c66
Acct-Authentic=1
Event-Timestamp=1331023036
NAS-Port-Type=5
Calling-Station-Id=192.168.1.174
Called-Station-Id=192.168.1.250
Mikrotik-Realm=localhost
MS-CHAP-Domain=localhost

radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusProcessor - Creating NasConnection from radius accounting packet
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusProcessor - Parent: null
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetApplication - TariffOptionMap: {}
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Accounting - Write new connection to DB
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Accounting - New connection id=6222
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Accounting - Write new session to DB
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Accounting - New session's id=6466
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] connection - 6222:6466 Register ip: 192.168.66.60
radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] RadiusListenerWorker - RESPONSE:
Packet type: Accounting-Response
Identifier: 218
Authenticator: {56 34 7A FB 94 D7 73 F0 72 67 4B 7A 62 79 2D D3}
Attributes:

Process time start: 13

accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] SessionTarifficationManager - Calculate for 06.03.2012 10:35:59
accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] SessionTarifficationManager - TariffOptionMap: {}
accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] SessionTarifficationManager - InetOptionSet: [1]
accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 inetServ[id=11] not active.
accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Found error 10
accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Already sent event to stop session.
accounting 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] InetApplication - TariffOptionMap: {}
accounting 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 inetServ[id=11] not active.
accounting 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Found error 10
accounting 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Sending event to stop session...

radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] RadiusListenerWorker - REQUEST:
Packet type: Accounting-Request
Identifier: 219
Authenticator: {4A 66 58 A4 82 16 C9 6B 1D 47 C0 5A 3B 46 0F 79}
Attributes:
User-Name=bg@localhost
NAS-Identifier=pt-noc
NAS-IP-Address=192.168.1.250
NAS-Port=370452
Service-Type=2
Framed-Protocol=1
Framed-IP-Address=192.168.66.60
Acct-Input-Octets=74
Acct-Output-Octets=70
Acct-Status-Type=2
Acct-Delay-Time=0
Acct-Session-Time=20
Acct-Input-Packets=8
Acct-Session-Id=81f07c66
Acct-Authentic=1
Acct-Terminate-Cause=10
Acct-Output-Packets=7
Event-Timestamp=1331023053
Acct-Output-Gigawords=0
Acct-Input-Gigawords=0
NAS-Port-Type=5
Calling-Station-Id=192.168.1.174
Called-Station-Id=192.168.1.250
Mikrotik-Realm=localhost
MS-CHAP-Domain=localhost

radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] InetRadiusProcessor - Session 81f07c66 found.
radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] InetNas - Stopping NasConnection
radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] connection - 6222:6466 Stopping NasConnection
radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] InetConnectionRuntime - Stopping connection with id=6222

mq 03-06/10:37:17 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=6222-0, iface=5:370452, sessId=81f07c66, start=06.03.
2012 10:37:16, uname=bg@localhost, addr=192.168.66.60]
mq 03-06/10:37:18 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.oss.systems.inventory.resource.common.event.IpResourceSubscrib
edEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: -1; timestamp: 1331023036578
radius 03-06/10:37:30 DEBUG [setup-sched-p-1-t-1] RadiusProcessor - After clean old rad sessions: 0
access 03-06/10:37:31 DEBUG [access-p-8-t-1] SessionCountManager - Run SessionCountManager...
connection 03-06/10:37:33 DEBUG [sa-p-9-t-4] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateM
odifyEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 5; inetServId: 11; connectionId: 6222; state: 0; accessCode: 10; timestamp: 133
1023053074
connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Do task deviceId: 5; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSa
StateModifyEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 5; inetServId: 11; connectionId: 6222; state: 0; accessCode: 10; timestam
p: 1331023053074
connection 03-06/10:37:33 INFO [sa-p-9-t-4] InetApplication - TariffOptionMap: {}
connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 11; call: true; o
ldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1
connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Processing deviceId:5; command ServiceActivatorEvent type=2; inetServId: 11; call
: true; oldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1
connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorSet - Invoking connectionModify
connection 03-06/10:37:33 INFO [sa-p-9-t-4] MTCoAServiceActivator - Connection modify: oldState: 1; newState: 0; oldOptionSet: [1]; newOptionSet: [1]
connection 03-06/10:37:33 INFO [sa-p-9-t-4] MTCoAServiceActivator - Connection close
connection 03-06/10:37:33 INFO [sa-p-9-t-4] MTCoAServiceActivator - Send PoD:
Packet type: Disconnect-Request
Identifier: 30
Authenticator: {AB 35 F4 7A 42 9D 2D CD 07 A0 78 8B 4F 92 25 57}
Attributes:
User-Name=bg@localhost
Framed-IP-Address=192.168.66.60

connection 03-06/10:37:33 INFO [sa-p-9-t-4] RadiusClient - Sending to /192.168.1.250:1700
Packet type: Disconnect-Request
Identifier: 30
Authenticator: {AB 35 F4 7A 42 9D 2D CD 07 A0 78 8B 4F 92 25 57}
Attributes:
User-Name=bg@localhost
Framed-IP-Address=192.168.66.60

connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Process event type[2] result=true
connection 03-06/10:37:33 INFO [pod-support-p1700] RadiusClient - Recieved from /192.168.1.250:1700
Packet type: Disconnect-ACK
Identifier: 30
Authenticator: {49 66 34 6A 08 25 BA EB B4 32 AE F9 D7 4C 18 3F}
Attributes:
NAS-Identifier=pt
NAS-IP-Address=192.168.1.250

03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 inetServ[id=11] not active.
03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Found error 10
03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Sending event to stop session...
03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] connection - 6221:6465 Stopping NasConnection
03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] connection - 6222:6466 Register ip: 192.168.66.60
03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 inetServ[id=11] not active.
03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Found error 10
03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Already sent event to stop session.
03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 inetServ[id=11] not active.
03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Found error 10
03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Sending event to stop session...
03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] connection - 6222:6466 Stopping NasConnection
03-06/10:37:35 INFO [accwrkr-3-p-10-t-1] connection - 6221:6465 Finish stopped call connection by sessionFinishTimeout
03-06/10:37:35 INFO [accwrkr-3-p-10-t-1] connection - 6221:6465 Finishing call session with lastActive=Tue Mar 06 10:37:30 EET 2012
03-06/10:37:35 INFO [accwrkr-3-p-10-t-1] connection - 6221:6465 Unregister ip: x.206.252.182
03-06/10:37:36 INFO [rdsLstnr-p-6-t-10] connection - 6223:6467 Register ip: 192.168.66.61
03-06/10:37:51 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 inetServ[id=11] not active.
03-06/10:37:51 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Found error 10
03-06/10:37:51 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Already sent event to stop session.
03-06/10:37:53 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 inetServ[id=11] not active.
03-06/10:37:53 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 Found error 10
03-06/10:37:53 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 Sending event to stop session...
03-06/10:37:53 INFO [rdsLstnr-p-6-t-1] connection - 6223:6467 Stopping NasConnection
03-06/10:37:55 INFO [accwrkr-3-p-10-t-1] connection - 6222:6466 Finish stopped call connection by sessionFinishTimeout
03-06/10:37:55 INFO [accwrkr-3-p-10-t-1] connection - 6222:6466 Finishing call session with lastActive=Tue Mar 06 10:37:51 EET 2012
03-06/10:37:55 INFO [accwrkr-3-p-10-t-1] connection - 6222:6466 Unregister ip: 192.168.66.60
03-06/10:37:56 INFO [rdsLstnr-p-6-t-2] connection - 6224:6468 Register ip: 192.168.66.62
03-06/10:38:11 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 inetServ[id=11] not active.
03-06/10:38:11 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 Found error 10
03-06/10:38:11 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 Already sent event to stop session.
03-06/10:38:13 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 inetServ[id=11] not active.
03-06/10:38:13 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 Found error 10
03-06/10:38:13 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 Sending event to stop session...
03-06/10:38:13 INFO [rdsLstnr-p-6-t-3] connection - 6224:6468 Stopping NasConnection
03-06/10:38:15 INFO [accwrkr-3-p-10-t-1] connection - 6223:6467 Finish stopped call connection by sessionFinishTimeout
03-06/10:38:15 INFO [accwrkr-3-p-10-t-1] connection - 6223:6467 Finishing call session with lastActive=Tue Mar 06 10:38:11 EET 2012
03-06/10:38:15 INFO [accwrkr-3-p-10-t-1] connection - 6223:6467 Unregister ip: 192.168.66.61
03-06/10:38:16 INFO [rdsLstnr-p-6-t-4] connection - 6225:6469 Register ip: 192.168.66.63
03-06/10:38:31 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 inetServ[id=11] not active.
03-06/10:38:31 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 Found error 10
03-06/10:38:31 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 Already sent event to stop session.
03-06/10:38:33 INFO [accwrkr-1-p-12-t-1] connection - 6225:6469 inetServ[id=11] not active.
03-06/10:38:33 INFO [accwrkr-1-p-12-t-1] connection - 6225:6469 Found error 10

Автор:	nik247 [ 06 мар 2012, 15:46 ]
Заголовок сообщения:	[5.2] InetAccounting - Reject-to-Accept - зацикливание сесси
[5.2] InetAccounting - Reject-to-Accept - странности Настроил Reject-to-Accept для Radius: Настройка NAS: Код: radius.disable.accessCodes=1,2,3,4,10,11,12,44 #категории ip адресов из ресурсов, из которых будут выдаваться адреса для отключенных ("пул", указывается во вкладке "IP ресурсы") radius.disable.ipCategories=13 В типах устройств прописан "Обработчик активации сервисов" - CoAServiseActivator. режим CoA не использую, только PoD. Вроде все работает. Клиента с монитора отключает по PoD. Далее переводим договор в статус "Оключен". Клиента отключат по PoD. Клиент переподключается - получает IP c "серого пула"- все ОК. Логи с InetAccess: Код: connection 03-06/10:37:13 DEBUG [sa-p-9-t-4] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateM odifyEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 5; inetServId: 11; connectionId: 6221; state: 0; accessCode: 10; timestamp: 133 1023033068 connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Do task deviceId: 5; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSa StateModifyEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 5; inetServId: 11; connectionId: 6221; state: 0; accessCode: 10; timestam p: 1331023033068 connection 03-06/10:37:13 INFO [sa-p-9-t-4] InetApplication - TariffOptionMap: {} connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 11; call: true; o ldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1 connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Processing deviceId:5; command ServiceActivatorEvent type=2; inetServId: 11; call : true; oldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1 connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorSet - Invoking connectionModify connection 03-06/10:37:13 INFO [sa-p-9-t-4] MTCoAServiceActivator - Connection modify: oldState: 1; newState: 0; oldOptionSet: [1]; newOptionSet: [1] connection 03-06/10:37:13 INFO [sa-p-9-t-4] MTCoAServiceActivator - Connection close connection 03-06/10:37:13 INFO [sa-p-9-t-4] MTCoAServiceActivator - Send PoD: Packet type: Disconnect-Request Identifier: 29 Authenticator: {7D 92 9B 3F FA A8 AA C2 FC 5A A9 FF 70 2D D0 EB} Attributes: User-Name=bg@localhost Framed-IP-Address=X.206.252.182 connection 03-06/10:37:13 INFO [sa-p-9-t-4] RadiusClient - Sending to /192.168.1.250:1700 Packet type: Disconnect-Request Identifier: 29 Authenticator: {7D 92 9B 3F FA A8 AA C2 FC 5A A9 FF 70 2D D0 EB} Attributes: User-Name=bg@localhost Framed-IP-Address=X.206.252.182 connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Process event type[2] result=true connection 03-06/10:37:13 INFO [pod-support-p1700] RadiusClient - Recieved from /192.168.1.250:1700 Packet type: Disconnect-ACK Identifier: 29 Authenticator: {9B 03 B6 09 B9 61 5F 08 92 87 CF 90 E3 EF A0 7A} Attributes: NAS-Identifier=pt NAS-IP-Address=192.168.1.250 connection 03-06/10:37:13 DEBUG [sa-p-9-t-4] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaAccoun tingEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 5; connectionId: 6221; timestamp: 1331023033086 connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Do task deviceId: 5; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSa AccountingEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 5; connectionId: 6221; timestamp: 1331023033086 connection 03-06/10:37:13 INFO [sa-p-9-t-4] InetApplication - TariffOptionMap: {} connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=5; inetServId: 11; call: true; o ldState: 0; newState: 0; oldOptionSet: 1; newOptionSet: 1 connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Processing deviceId:5; command ServiceActivatorEvent type=5; inetServId: 11; call : true; oldState: 0; newState: 0; oldOptionSet: 1; newOptionSet: 1 connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorSet - Invoking onAccountingStop connection 03-06/10:37:13 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Process event type[5] result=true mq 03-06/10:37:13 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.accounting.event.InetAccountingEvent] m oduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; type: 2; deviceId: 5; connectionId: 6221; timestamp: 1331023033086 mq 03-06/10:37:13 INFO [event-proc-p-2-t-1] InetConnectionManager - Remove connection: InetConnection [id=6221-0, iface=5:370451, sessId=81f07c65, start=06. 03.2012 10:35:59, uname=bg@localhost, addr=91.206.252.182] radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] RadiusListenerWorker - REQUEST: Packet type: Access-Request Identifier: 217 Authenticator: {CC EC F0 74 6E 20 20 6F CC 7B AD 57 55 AA EF 55} Attributes: User-Name=bg@localhost NAS-Identifier=pt NAS-IP-Address=192.168.1.250 NAS-Port=370452 Service-Type=2 Framed-Protocol=1 Calling-Station-Id=192.168.1.174 NAS-Port-Type=5 Called-Station-Id=192.168.1.250 Mikrotik-Realm=localhost MS-CHAP2-Response={01 00 B6 49 B5 FF 17 8F A3 74 DD C9 21 C2 85 4B 28 B1 00 00 00 00 00 00 00 00 25 DE E7 44 3C 7C EC 20 3E 2A EC 41 F0 CF E8 F7 38 2C A3 D C 8F 12 38 50} MS-CHAP-Domain=localhost MS-CHAP-Challenge={20 58 E2 66 65 14 7D 70 79 D3 23 32 CD 6A B5 59} radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusProcessor - Create new radius session. radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - try checkDigestMD5Password radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - digestAttributes=null radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - digestResponse=null radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - user =null realm =null nonce = null method = null uri = null radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - try all in one string radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] RadiusUtils - digestAttribute=null radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusProcessor - [username=bg] Authenticated as inetServId:11 radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] InetRadiusProcessor - MAC-address from request: radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Access - inetServ[id=11] deviceState not active (accessCode=44). radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusProcessor - Return code=0 radius 03-06/10:37:16 DEBUG [rdsLstnr-p-6-t-8] ProcessorRequest - Sending to /192.168.1.250:34989 radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusListenerWorker - RESPONSE: Packet type: Access-Accept Identifier: 217 Authenticator: {CA 6F 0F 17 83 99 26 CF 14 3B C5 BC 22 54 CB F4} Attributes: Framed-IP-Address=192.168.66.60 Mikrotik-Address-List=INET_DISABLED MS-MPPE-Recv-Key={93 59 22 20 17 1C 47 03 E0 22 2D DA 3B 75 51 B0 B5 9C D9 2F E3 72 12 64 14 7D 89 FF EB EE 60 6F 31 52} MS-MPPE-Send-Key={ED 13 D2 A0 29 0A 55 56 0F 97 D1 4C 8D 41 9D 5B 81 EE BA B7 BB F6 AE C0 F2 A5 AB 1A 2A 3C A1 7B 72 6A} MS-CHAP2-Success={3F 53 3D 36 46 35 39 46 34 43 31 32 39 44 43 36 42 35 42 39 35 31 43 43 38 37 39 33 45 34 45 45 41 44 39 41 42 39 36 36 36 31 43} Process time auth: 6 Логи с InetAccounting: Код: accounting 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] InetApplication - TariffOptionMap: {} accounting 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 inetServ[id=11] not active. accounting 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Found error 10 accounting 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Sending event to stop session... radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] RadiusListenerWorker - REQUEST: Packet type: Accounting-Request Identifier: 216 Authenticator: {AD 88 87 20 59 DC 66 6E FC C4 3E FD CA DD DF 3A} Attributes: User-Name=bg@localhost NAS-Identifier=pt NAS-IP-Address=192.168.1.250 NAS-Port=370451 Service-Type=2 Framed-Protocol=1 Framed-IP-Address=X.206.252.182 Acct-Input-Octets=74 Acct-Output-Octets=70 Acct-Status-Type=2 Acct-Delay-Time=0 Acct-Session-Time=76 Acct-Input-Packets=8 Acct-Session-Id=81f07c65 Acct-Authentic=1 Acct-Terminate-Cause=10 Acct-Output-Packets=7 Event-Timestamp=1331023033 Acct-Output-Gigawords=0 Acct-Input-Gigawords=0 NAS-Port-Type=5 Calling-Station-Id=192.168.1.174 Called-Station-Id=192.168.1.250 Mikrotik-Realm=localhost MS-CHAP-Domain=localhost radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] InetRadiusProcessor - Session 81f07c65 found. radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] InetNas - Stopping NasConnection radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] connection - 6221:6465 Stopping NasConnection radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] InetConnectionRuntime - Stopping connection with id=6221 radius 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] RadiusListenerWorker - RESPONSE: Packet type: Accounting-Response Identifier: 216 Authenticator: {DE 9F 34 38 C9 F3 74 74 4B 3A 37 B8 0C 2C BB 92} Attributes: Process time stop: 12 accounting 03-06/10:37:16 INFO [accwrkr-1-p-12-t-1] InetApplication - TariffOptionMap: {} accounting 03-06/10:37:16 INFO [accwrkr-1-p-12-t-1] InetApplication - TariffOptionMap: {} radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] RadiusListenerWorker - REQUEST: Packet type: Accounting-Request Identifier: 218 Authenticator: {B3 D3 20 E1 D4 53 2C E2 D2 19 0C A0 4E 68 70 A6} Attributes: User-Name=bg@localhost NAS-Identifier=pt NAS-IP-Address=192.168.1.250 NAS-Port=370452 Service-Type=2 Framed-Protocol=1 Framed-IP-Address=192.168.66.60 Acct-Status-Type=1 Acct-Delay-Time=0 Acct-Session-Id=81f07c66 Acct-Authentic=1 Event-Timestamp=1331023036 NAS-Port-Type=5 Calling-Station-Id=192.168.1.174 Called-Station-Id=192.168.1.250 Mikrotik-Realm=localhost MS-CHAP-Domain=localhost radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusProcessor - Creating NasConnection from radius accounting packet radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetRadiusProcessor - Parent: null radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] InetApplication - TariffOptionMap: {} radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Accounting - Write new connection to DB radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Accounting - New connection id=6222 radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Accounting - Write new session to DB radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] Accounting - New session's id=6466 radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] connection - 6222:6466 Register ip: 192.168.66.60 radius 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] RadiusListenerWorker - RESPONSE: Packet type: Accounting-Response Identifier: 218 Authenticator: {56 34 7A FB 94 D7 73 F0 72 67 4B 7A 62 79 2D D3} Attributes: Process time start: 13 До этого момента все хорошо, а вот через несколько секунд начинаются чудеса: InetAccounting дает комманду на отключение сессии. Логи с InetAccounting: Код: accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] SessionTarifficationManager - Calculate for 06.03.2012 10:35:59 accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] SessionTarifficationManager - TariffOptionMap: {} accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] SessionTarifficationManager - InetOptionSet: [1] accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 inetServ[id=11] not active. accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Found error 10 accounting 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Already sent event to stop session. accounting 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] InetApplication - TariffOptionMap: {} accounting 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 inetServ[id=11] not active. accounting 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Found error 10 accounting 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Sending event to stop session... radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] RadiusListenerWorker - REQUEST: Packet type: Accounting-Request Identifier: 219 Authenticator: {4A 66 58 A4 82 16 C9 6B 1D 47 C0 5A 3B 46 0F 79} Attributes: User-Name=bg@localhost NAS-Identifier=pt-noc NAS-IP-Address=192.168.1.250 NAS-Port=370452 Service-Type=2 Framed-Protocol=1 Framed-IP-Address=192.168.66.60 Acct-Input-Octets=74 Acct-Output-Octets=70 Acct-Status-Type=2 Acct-Delay-Time=0 Acct-Session-Time=20 Acct-Input-Packets=8 Acct-Session-Id=81f07c66 Acct-Authentic=1 Acct-Terminate-Cause=10 Acct-Output-Packets=7 Event-Timestamp=1331023053 Acct-Output-Gigawords=0 Acct-Input-Gigawords=0 NAS-Port-Type=5 Calling-Station-Id=192.168.1.174 Called-Station-Id=192.168.1.250 Mikrotik-Realm=localhost MS-CHAP-Domain=localhost radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] InetRadiusProcessor - Session 81f07c66 found. radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] InetNas - Stopping NasConnection radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] connection - 6222:6466 Stopping NasConnection radius 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] InetConnectionRuntime - Stopping connection with id=6222 Логи с InetAccess: Код: mq 03-06/10:37:17 INFO [event-proc-p-2-t-1] InetConnectionManager - Add connection: InetConnection [id=6222-0, iface=5:370452, sessId=81f07c66, start=06.03. 2012 10:37:16, uname=bg@localhost, addr=192.168.66.60] mq 03-06/10:37:18 DEBUG [event-proc-p-2-t-1] Consumer - Caught BGInetAccounting:Event[ru.bitel.oss.systems.inventory.resource.common.event.IpResourceSubscrib edEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: -1; timestamp: 1331023036578 radius 03-06/10:37:30 DEBUG [setup-sched-p-1-t-1] RadiusProcessor - After clean old rad sessions: 0 access 03-06/10:37:31 DEBUG [access-p-8-t-1] SessionCountManager - Run SessionCountManager... connection 03-06/10:37:33 DEBUG [sa-p-9-t-4] AcknowledgeConsumer - Caught BGInetAccounting:Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSaStateM odifyEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 5; inetServId: 11; connectionId: 6222; state: 0; accessCode: 10; timestamp: 133 1023053074 connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Do task deviceId: 5; Event[ru.bitel.bgbilling.modules.inet.access.sa.event.InetSa StateModifyEvent] moduleId: 5; pluginId: no; cid: 1; scid: -1; userId: 0; deviceId: 5; inetServId: 11; connectionId: 6222; state: 0; accessCode: 10; timestam p: 1331023053074 connection 03-06/10:37:33 INFO [sa-p-9-t-4] InetApplication - TariffOptionMap: {} connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Command result event: ServiceActivatorEvent type=2; inetServId: 11; call: true; o ldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1 connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Processing deviceId:5; command ServiceActivatorEvent type=2; inetServId: 11; call : true; oldState: 1; newState: 0; oldOptionSet: 1; newOptionSet: 1 connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorSet - Invoking connectionModify connection 03-06/10:37:33 INFO [sa-p-9-t-4] MTCoAServiceActivator - Connection modify: oldState: 1; newState: 0; oldOptionSet: [1]; newOptionSet: [1] connection 03-06/10:37:33 INFO [sa-p-9-t-4] MTCoAServiceActivator - Connection close connection 03-06/10:37:33 INFO [sa-p-9-t-4] MTCoAServiceActivator - Send PoD: Packet type: Disconnect-Request Identifier: 30 Authenticator: {AB 35 F4 7A 42 9D 2D CD 07 A0 78 8B 4F 92 25 57} Attributes: User-Name=bg@localhost Framed-IP-Address=192.168.66.60 connection 03-06/10:37:33 INFO [sa-p-9-t-4] RadiusClient - Sending to /192.168.1.250:1700 Packet type: Disconnect-Request Identifier: 30 Authenticator: {AB 35 F4 7A 42 9D 2D CD 07 A0 78 8B 4F 92 25 57} Attributes: User-Name=bg@localhost Framed-IP-Address=192.168.66.60 connection 03-06/10:37:33 INFO [sa-p-9-t-4] ServiceActivatorDeviceWorker - Process event type[2] result=true connection 03-06/10:37:33 INFO [pod-support-p1700] RadiusClient - Recieved from /192.168.1.250:1700 Packet type: Disconnect-ACK Identifier: 30 Authenticator: {49 66 34 6A 08 25 BA EB B4 32 AE F9 D7 4C 18 3F} Attributes: NAS-Identifier=pt NAS-IP-Address=192.168.1.250 И так это длится по кругу до бесконечности с длиной сессий 20 сек пока не переведеш статус договора в "Активен". Код: 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 inetServ[id=11] not active. 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Found error 10 03-06/10:37:13 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Sending event to stop session... 03-06/10:37:13 INFO [rdsLstnr-p-6-t-7] connection - 6221:6465 Stopping NasConnection 03-06/10:37:16 INFO [rdsLstnr-p-6-t-8] connection - 6222:6466 Register ip: 192.168.66.60 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 inetServ[id=11] not active. 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Found error 10 03-06/10:37:31 INFO [accwrkr-1-p-12-t-1] connection - 6221:6465 Already sent event to stop session. 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 inetServ[id=11] not active. 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Found error 10 03-06/10:37:33 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Sending event to stop session... 03-06/10:37:33 INFO [rdsLstnr-p-6-t-9] connection - 6222:6466 Stopping NasConnection 03-06/10:37:35 INFO [accwrkr-3-p-10-t-1] connection - 6221:6465 Finish stopped call connection by sessionFinishTimeout 03-06/10:37:35 INFO [accwrkr-3-p-10-t-1] connection - 6221:6465 Finishing call session with lastActive=Tue Mar 06 10:37:30 EET 2012 03-06/10:37:35 INFO [accwrkr-3-p-10-t-1] connection - 6221:6465 Unregister ip: x.206.252.182 03-06/10:37:36 INFO [rdsLstnr-p-6-t-10] connection - 6223:6467 Register ip: 192.168.66.61 03-06/10:37:51 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 inetServ[id=11] not active. 03-06/10:37:51 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Found error 10 03-06/10:37:51 INFO [accwrkr-1-p-12-t-1] connection - 6222:6466 Already sent event to stop session. 03-06/10:37:53 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 inetServ[id=11] not active. 03-06/10:37:53 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 Found error 10 03-06/10:37:53 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 Sending event to stop session... 03-06/10:37:53 INFO [rdsLstnr-p-6-t-1] connection - 6223:6467 Stopping NasConnection 03-06/10:37:55 INFO [accwrkr-3-p-10-t-1] connection - 6222:6466 Finish stopped call connection by sessionFinishTimeout 03-06/10:37:55 INFO [accwrkr-3-p-10-t-1] connection - 6222:6466 Finishing call session with lastActive=Tue Mar 06 10:37:51 EET 2012 03-06/10:37:55 INFO [accwrkr-3-p-10-t-1] connection - 6222:6466 Unregister ip: 192.168.66.60 03-06/10:37:56 INFO [rdsLstnr-p-6-t-2] connection - 6224:6468 Register ip: 192.168.66.62 03-06/10:38:11 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 inetServ[id=11] not active. 03-06/10:38:11 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 Found error 10 03-06/10:38:11 INFO [accwrkr-1-p-12-t-1] connection - 6223:6467 Already sent event to stop session. 03-06/10:38:13 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 inetServ[id=11] not active. 03-06/10:38:13 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 Found error 10 03-06/10:38:13 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 Sending event to stop session... 03-06/10:38:13 INFO [rdsLstnr-p-6-t-3] connection - 6224:6468 Stopping NasConnection 03-06/10:38:15 INFO [accwrkr-3-p-10-t-1] connection - 6223:6467 Finish stopped call connection by sessionFinishTimeout 03-06/10:38:15 INFO [accwrkr-3-p-10-t-1] connection - 6223:6467 Finishing call session with lastActive=Tue Mar 06 10:38:11 EET 2012 03-06/10:38:15 INFO [accwrkr-3-p-10-t-1] connection - 6223:6467 Unregister ip: 192.168.66.61 03-06/10:38:16 INFO [rdsLstnr-p-6-t-4] connection - 6225:6469 Register ip: 192.168.66.63 03-06/10:38:31 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 inetServ[id=11] not active. 03-06/10:38:31 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 Found error 10 03-06/10:38:31 INFO [accwrkr-1-p-12-t-1] connection - 6224:6468 Already sent event to stop session. 03-06/10:38:33 INFO [accwrkr-1-p-12-t-1] connection - 6225:6469 inetServ[id=11] not active. 03-06/10:38:33 INFO [accwrkr-1-p-12-t-1] connection - 6225:6469 Found error 10 Не подскажете в чем может быть проблема?

Автор:	Amir [ 06 мар 2012, 15:55 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Причина в том, что Inet не знает, что это это сессия с закрытым доступом. Нужно либо указать, чтобы Access сервер создавал запись при отправке Access-Accept: Код: #при выдаче access-accept добавлять запись в базу #необходимо, если используется reject-to-accept и по старт пакету нельзя определить в каком состоянии соединение connection.start.fromAccept=1 Либо указать, при каких атрибутах в Accounting-пакете считать, что это сессия с закрытым доступом: Код: radius.disable.pattern.attributes=HTTP-Mikrotik-Address-List=INET_DISABLED Или и то, и то вместе.

Автор:	nik247 [ 06 мар 2012, 16:48 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Спасибо. Помогло вот это: Код: #при выдаче access-accept добавлять запись в базу #необходимо, если используется reject-to-accept и по старт пакету нельзя определить в каком состоянии соединение connection.start.fromAccept=1 В АСС пакетах не могу передавать спец.атрибутов. для фейковой сессии. Скажите пож-ста, а при возврате договора в состояние "Активен", как передать PoD? Или только скриптом?

Автор:	Amir [ 06 мар 2012, 16:54 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
А сам не переключает? Вроде должен, раз уже знает, что соединение в состоянии "отключен".

Автор:	nik247 [ 06 мар 2012, 18:09 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Amir писал(а): А сам не переключает? Вроде должен, раз уже знает, что соединение в состоянии "отключен". Не отключается - в логах не видел посылок PoD. Зацикливание продолжается.... Опция connection.start.fromAccept=1 не помогает.... Помогает остановить loop "перечитывание конфигурации", но только на текущую сессию.... Тоесть так: 1) отключаем. договор - пошло кольцо фейковых сессий по 20 сек. 2) "перечитываем конфигурацию на серверах" - loop закончился. 3) включаем договор - PoD не посылается - дергаем сессию руками - получаем нормальный IP 4) отключаем. договор -> пункт 1)

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

[5.2] InetAccounting - Reject-to-Accept - зацикливание сесси http://forum.bitel.ru/viewtopic.php?f=44&t=6535	Страница 1 из 1

Автор:	Amir [ 06 мар 2012, 18:55 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
А radius.disable.pattern.attributes= точно ни в каком виде не прописано? Можете логи отправить тогда? В базе, в таблице inet_connection_ поле deviceState=0 у соединения, когда подключается со статусом Закрыт?

Автор:	nik247 [ 06 мар 2012, 20:59 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Amir писал(а): А radius.disable.pattern.attributes= точно ни в каком виде не прописано? Можете логи отправить тогда? В базе, в таблице inet_connection_ поле deviceState=0 у соединения, когда подключается со статусом Закрыт? Прописан только: Код: radius.disable.attributes=Mikrotik-Address-List=INET_DISABLED deviceState=1 всегда Логи BGAccess и BGAccounting выслал на почту. Спасибо.

Автор:	Amir [ 07 мар 2012, 02:46 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Надо это убрать, если такого атрибута, как вы говорите, не приходит в аккунтинге: Код: radius.disable.attributes=Mikrotik-Address-List=INET_DISABLED Скорее всего и при изменении статуса договора на активен заработает. Когда этот параметр задан для каждого аккаунтинг пакета проверяется, присутствуют ли указанные атрибуты. Если присутствуют - означает что сессия в состоянии "отключена", а если нет - что сессия "подключена". Так как параметр прописан, при старте сессия переключается в состояние "подключен", inet думает, что это не fake сессия.

Автор:	nik247 [ 13 мар 2012, 17:47 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Amir писал(а): Надо это убрать, если такого атрибута, как вы говорите, не приходит в аккунтинге: Код: radius.disable.attributes=Mikrotik-Address-List=INET_DISABLED Скорее всего и при изменении статуса договора на активен заработает. Когда этот параметр задан для каждого аккаунтинг пакета проверяется, присутствуют ли указанные атрибуты. Если присутствуют - означает что сессия в состоянии "отключена", а если нет - что сессия "подключена". Так как параметр прописан, при старте сессия переключается в состояние "подключен", inet думает, что это не fake сессия. radius.disable.attributes отключил. Но результат тот-же - зацикливание. Код: accounting 03-13/13:45:08 INFO [accwrkr-1-p-12-t-1] connection - 10483:10742 inetServ[id=11] not active. accounting 03-13/13:45:08 INFO [accwrkr-1-p-12-t-1] connection - 10483:10742 Found error 10 accounting 03-13/13:45:08 INFO [accwrkr-1-p-12-t-1] connection - 10483:10742 Sending event to stop session... accounting 03-13/13:45:09 INFO [accwrkr-3-p-10-t-1] connection - 10482:10741 Finish stopped call connection by sessionFinishTimeout accounting 03-13/13:45:09 INFO [accwrkr-3-p-10-t-1] connection - 10482:10741 Finishing call session with lastActive=Tue Mar 13 13:45:15 FET 2012 accounting 03-13/13:45:09 INFO [accwrkr-3-p-10-t-1] Accounting - Finishing session 10741 Обновления все последние от 13.03.2012

Автор:	Amir [ 13 мар 2012, 17:54 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Можете доступ дать?

Автор:	nik247 [ 13 мар 2012, 18:39 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Amir писал(а): Можете доступ дать? Отписался в личку, но сообщение висит в исходящих....

Автор:	Amir [ 13 мар 2012, 19:58 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Сейчас вроде бы нормально отрабатывает. Проблемы были в том, что в сервере было connection.start.fromAccess, а в wiki connection.start.fromAccept. Теперь работают оба варианта. В Access-Request от NAS'а отсутствует Acct-Session-Id, InetAccounting не мог найти waiting(status=0) запись. В последнем билде теперь достаточно NAS-Port-Id.

Автор:	nik247 [ 13 мар 2012, 20:49 ]
Заголовок сообщения:	Re: [5.2] InetAccounting - Reject-to-Accept - зацикливание с
Amir писал(а): Сейчас вроде бы нормально отрабатывает. Проблемы были в том, что в сервере было connection.start.fromAccess, а в wiki connection.start.fromAccept. Теперь работают оба варианта. В Access-Request от NAS'а отсутствует Acct-Session-Id, InetAccounting не мог найти waiting(status=0) запись. В последнем билде теперь достаточно NAS-Port-Id. Большое спасибо за решение этой проблемы.

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