Технические вопросы по UTM 5.0
slash
Сообщения: 33 Зарегистрирован: Пн янв 25, 2010 17:02
Сообщение
slash Пт сен 10, 2010 13:40
Подскажите пожалуйста, в чем может быть проблема при авторизации по vpn.
После ввода нового пользователя в биллинг, при попытке этим пользователем подключиться по впн, вылетает ошибка 691, хотя логин и пароль вводиться правильный.
Приходиться рестартовать mpd и utm_radius, после чего пользователь нормально авторизуется по впн. Где копать?
Freebsd 7.2 UTM-5.2.1.006 mpd5
Конфиг mpd
Код: Выделить всё
startup:
set netflow peer 127.0.0.1 9996
default:
load pptp_server
pptp_server:
create bundle template B
set iface enable proxy-arp
set iface enable netflow-in
set iface enable netflow-out
set iface idle 1800
set iface enable tcpmssfix
set ipcp yes vjcomp
set ipcp ranges 192.168.0.10/29 10.10.1.0/32
set ipcp dns 192.168.0.10
set bundle enable compression
create link template L pptp
set link action bundle B
set link enable multilink
set link yes acfcomp protocomp
set link no pap chap
set link enable chap
set link enable peer-as-calling
load radius
set link keep-alive 10 60
set link mtu 1460
set pptp self 192.168.0.10
set pptp disable windowing
set pptp enable always-ack
set link enable incoming
radius:
set radius config /etc/radius.conf
set radius server 127.0.0.1 secret 1812 1813
set radius retries 3
set radius timeout 3
set radius me 127.0.0.1
set auth acct-update 300
set auth enable radius-auth
set auth enable radius-acct
set auth max-logins 1
set radius enable message-authentic
slash
Сообщения: 33 Зарегистрирован: Пн янв 25, 2010 17:02
Сообщение
slash Пт сен 10, 2010 15:19
До рестарта mpd после ввода нового пользователя в биллинг
Код: Выделить всё
Sep 10 12:52:54 stat mpd: [L-4] CHAP: rec'd RESPONSE #1 len: 58
Sep 10 12:52:54 stat mpd: [L-4] Name: "test"
Sep 10 12:52:54 stat mpd: [L-4] AUTH: Trying RADIUS
Sep 10 12:52:54 stat mpd: [L-4] RADIUS: Authenticating user 'test'
Sep 10 12:52:54 stat mpd: [L-4] RADIUS: Rec'd RAD_ACCESS_REJECT for user 'test'
Sep 10 12:52:54 stat mpd: [L-4] AUTH: RADIUS returned: failed
Sep 10 12:52:54 stat mpd: [L-4] AUTH: Trying INTERNAL
Sep 10 12:52:54 stat mpd: [L-4] AUTH: User "test" not found in secret file
Sep 10 12:52:54 stat mpd: [L-4] AUTH: INTERNAL returned: failed
Sep 10 12:52:54 stat mpd: [L-4] AUTH: ran out of backends
Sep 10 12:52:54 stat mpd: [L-4] CHAP: Auth return status: failed
Sep 10 12:52:54 stat mpd: [L-4] CHAP: Reply message: E=691 R=0 M=Authorization failed.
Sep 10 12:52:54 stat mpd: [L-4] CHAP: sending FAILURE #1 len: 37
Sep 10 12:52:54 stat mpd: [L-4] LCP: authorization failed
Sep 10 12:52:54 stat mpd: [L-4] LCP: parameter negotiation failed
Sep 10 12:52:54 stat mpd: [L-4] LCP: state change Opened --> Stopping
Sep 10 12:52:54 stat mpd: [L-4] LCP: SendTerminateReq #4
Sep 10 12:52:54 stat mpd: [L-4] LCP: LayerDown
Sep 10 12:52:55 stat mpd: [L-4] LCP: rec'd Terminate Ack #4 (Stopping)
Sep 10 12:52:55 stat mpd: [L-4] LCP: state change Stopping --> Stopped
Sep 10 12:52:55 stat mpd: [L-4] LCP: LayerFinish
Sep 10 12:52:55 stat mpd: [L-4] PPTP call terminated
Sep 10 12:52:55 stat mpd: [L-4] Link: DOWN event
Sep 10 12:52:55 stat mpd: [L-4] LCP: Close event
Sep 10 12:52:55 stat mpd: [L-4] LCP: state change Stopped --> Closed
Sep 10 12:52:55 stat mpd: [L-4] LCP: Down event
Sep 10 12:52:55 stat mpd: [L-4] LCP: state change Closed --> Initial
Sep 10 12:52:55 stat mpd: [L-4] Link: SHUTDOWN event
Sep 10 12:52:55 stat mpd: [L-4] Link: Shutdown
Sep 10 12:53:01 stat mpd: caught fatal signal term
Sep 10 12:53:01 stat mpd: [B-1] IFACE: Close event
Sep 10 12:53:01 stat mpd: [B-1] IPCP: Close event
Sep 10 12:53:01 stat mpd: [B-1] IPCP: state change Opened --> Closing
Sep 10 12:53:01 stat mpd: [B-1] IPCP: SendTerminateReq #3
Sep 10 12:53:01 stat mpd: [B-1] IPCP: LayerDown
Sep 10 12:53:01 stat mpd: [B-1] IFACE: Down event
Sep 10 12:53:01 stat mpd: [B-1] CCP: Close event
Sep 10 12:53:01 stat mpd: [B-1] CCP: state change Stopped --> Closed
Sep 10 12:53:01 stat mpd: [B-2] IFACE: Close event
Sep 10 12:53:01 stat mpd: [B-2] IPCP: Close event
Sep 10 12:53:01 stat mpd: [B-2] IPCP: state change Opened --> Closing
Sep 10 12:53:01 stat mpd: [B-2] IPCP: SendTerminateReq #3
Sep 10 12:53:01 stat mpd: [B-2] IPCP: LayerDown
Sep 10 12:53:01 stat mpd: [B-2] IFACE: Down event
Sep 10 12:53:01 stat mpd: [B-2] CCP: Close event
Sep 10 12:53:01 stat mpd: [B-2] CCP: state change Stopped --> Closed
Sep 10 12:53:01 stat mpd: [B-3] IFACE: Close event
Sep 10 12:53:01 stat mpd: [B-3] IPCP: Close event
Sep 10 12:53:01 stat mpd: [B-3] IPCP: state change Opened --> Closing
Sep 10 12:53:01 stat mpd: [B-3] IPCP: SendTerminateReq #3
Sep 10 12:53:01 stat mpd: [B-3] IPCP: LayerDown
Sep 10 12:53:01 stat mpd: [B-3] IFACE: Down event
Sep 10 12:53:01 stat mpd: [B-3] CCP: Close event
Sep 10 12:53:01 stat mpd: [B-3] CCP: state change Stopped --> Closed
Sep 10 12:53:01 stat mpd: [B-2] IPCP: rec'd Terminate Ack #3 (Closing)
Sep 10 12:53:01 stat mpd: [B-2] IPCP: state change Closing --> Closed
Sep 10 12:53:01 stat mpd: [B-2] IPCP: LayerFinish
Sep 10 12:53:01 stat mpd: [B-2] Bundle: No NCPs left. Closing links...
Sep 10 12:53:01 stat mpd: [B-2] Bundle: closing link "L-2"...
Sep 10 12:53:01 stat mpd: [L-2] Link: CLOSE event
Sep 10 12:53:01 stat mpd: [L-2] LCP: Close event
Sep 10 12:53:01 stat mpd: [L-2] LCP: state change Opened --> Closing
Sep 10 12:53:01 stat mpd: [L-2] Link: Leave bundle "B-2"
Sep 10 12:53:01 stat mpd: [B-2] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Sep 10 12:53:01 stat mpd: [B-2] IPCP: Close event
Sep 10 12:53:01 stat mpd: [B-2] CCP: Close event
Sep 10 12:53:01 stat mpd: [B-2] IPCP: Down event
Sep 10 12:53:01 stat mpd: [B-2] IPCP: state change Closed --> Initial
Sep 10 12:53:01 stat mpd: [B-2] CCP: Down event
Sep 10 12:53:01 stat mpd: [B-2] CCP: state change Closed --> Initial
Sep 10 12:53:01 stat mpd: [B-2] Bundle: Shutdown
Sep 10 12:53:01 stat mpd: [L-2] LCP: SendTerminateReq #4
Sep 10 12:53:01 stat mpd: [L-2] LCP: LayerDown
Sep 10 12:53:01 stat mpd: [L-2] RADIUS: Accounting user 'natali' (Type: 2)
Sep 10 12:53:01 stat mpd: [L-2] RADIUS: Rec'd RAD_ACCOUNTING_RESPONSE for user 'natali'
Sep 10 12:53:01 stat mpd: [B-3] IPCP: rec'd Terminate Ack #3 (Closing)
Sep 10 12:53:01 stat mpd: [B-3] IPCP: state change Closing --> Closed
После рестарта mpd
Sep 10 12:53:03 stat mpd: PPTP: stop waiting for connection on 192.168.0.10 1723
Sep 10 12:53:03 stat mpd: process 36974 terminated
Sep 10 12:53:07 stat mpd: Multi-link PPP daemon for FreeBSD
Sep 10 12:53:07 stat mpd:
Sep 10 12:53:07 stat mpd: process 41698 started, version 5.5 (root@proxy2.sieit.ru 15:11 1-Aug-2010)
Sep 10 12:53:07 stat mpd: PPTP: waiting for connection on 192.168.0.10 1723
Sep 10 12:53:37 stat mpd: [L-1] Accepting PPTP connection
Sep 10 12:53:37 stat mpd: [L-1] Link: OPEN event
Sep 10 12:53:37 stat mpd: [L-1] LCP: Open event
Sep 10 12:53:37 stat mpd: [L-1] LCP: state change Initial --> Starting
Sep 10 12:53:37 stat mpd: [L-1] LCP: LayerStart
Sep 10 12:53:37 stat mpd: [L-1] PPTP: attaching to peer's outgoing call
Sep 10 12:53:37 stat mpd: [L-1] Link: UP event
Sep 10 12:53:37 stat mpd: [L-1] LCP: Up event
Sep 10 12:53:37 stat mpd: [L-1] LCP: state change Starting --> Req-Sent
Sep 10 12:53:37 stat mpd: [L-1] LCP: SendConfigReq #1
Sep 10 12:53:37 stat mpd: [L-1] ACFCOMP
Sep 10 12:53:37 stat mpd: [L-1] PROTOCOMP
Sep 10 12:53:37 stat mpd: [L-1] MRU 1500
Sep 10 12:53:37 stat mpd: [L-1] MAGICNUM 41a3a828
Sep 10 12:53:37 stat mpd: [L-1] AUTHPROTO CHAP MSOFTv2
Sep 10 12:53:37 stat mpd: [L-1] MP MRRU 2048
Sep 10 12:53:37 stat mpd: [L-1] MP SHORTSEQ
Sep 10 12:53:37 stat mpd: [L-1] ENDPOINTDISC [802.1] 00 15 5d 00 43 00
Sep 10 12:53:37 stat mpd: [L-1] LCP: rec'd Configure Request #0 (Req-Sent)
Sep 10 12:53:37 stat mpd: [L-1] MRU 1400
Sep 10 12:53:37 stat mpd: [L-1] MAGICNUM 56b04c9f
Sep 10 12:53:37 stat mpd: [L-1] PROTOCOMP
Sep 10 12:53:37 stat mpd: [L-1] ACFCOMP
Sep 10 12:53:37 stat mpd: [L-1] CALLBACK 6
Sep 10 12:53:37 stat mpd: [L-1] LCP: SendConfigRej #0
Sep 10 12:53:37 stat mpd: [L-1] CALLBACK 6
Sep 10 12:53:37 stat mpd: [L-1] LCP: rec'd Configure Request #1 (Req-Sent)
Sep 10 12:53:37 stat mpd: [L-1] MRU 1400
Sep 10 12:53:37 stat mpd: [L-1] MAGICNUM 56b04c9f
Sep 10 12:53:37 stat mpd: [L-1] PROTOCOMP
Sep 10 12:53:37 stat mpd: [L-1] ACFCOMP
Sep 10 12:53:37 stat mpd: [L-1] LCP: state change Req-Sent --> Ack-Sent
Sep 10 12:53:39 stat mpd: [L-1] LCP: SendConfigReq #2
Sep 10 12:53:39 stat mpd: [L-1] ACFCOMP
Sep 10 12:53:39 stat mpd: [L-1] PROTOCOMP
Sep 10 12:53:39 stat mpd: [L-1] MRU 1500
Sep 10 12:53:39 stat mpd: [L-1] MAGICNUM 41a3a828
Sep 10 12:53:39 stat mpd: [L-1] AUTHPROTO CHAP MSOFTv2
Sep 10 12:53:39 stat mpd: [L-1] MP MRRU 2048
Sep 10 12:53:39 stat mpd: [L-1] MP SHORTSEQ
Sep 10 12:53:39 stat mpd: [L-1] ENDPOINTDISC [802.1] 00 15 5d 00 43 00
Sep 10 12:53:39 stat mpd: [L-1] LCP: rec'd Configure Reject #2 (Ack-Sent)
Sep 10 12:53:39 stat mpd: [L-1] MP MRRU 2048
Sep 10 12:53:39 stat mpd: [L-1] MP SHORTSEQ
Sep 10 12:53:39 stat mpd: [L-1] ENDPOINTDISC [802.1] 00 15 5d 00 43 00
Sep 10 12:53:39 stat mpd: [L-1] LCP: SendConfigReq #3
Sep 10 12:53:39 stat mpd: [L-1] ACFCOMP
Sep 10 12:53:39 stat mpd: [L-1] PROTOCOMP
Sep 10 12:53:39 stat mpd: [L-1] MRU 1500
Sep 10 12:53:39 stat mpd: [L-1] MAGICNUM 41a3a828
Sep 10 12:53:39 stat mpd: [L-1] AUTHPROTO CHAP MSOFTv2
Sep 10 12:53:39 stat mpd: [L-1] LCP: rec'd Configure Ack #3 (Ack-Sent)
Sep 10 12:53:39 stat mpd: [L-1] ACFCOMP
Sep 10 12:53:39 stat mpd: [L-1] PROTOCOMP
Sep 10 12:53:39 stat mpd: [L-1] MRU 1500
Sep 10 12:53:39 stat mpd: [L-1] MAGICNUM 41a3a828
Sep 10 12:53:39 stat mpd: [L-1] AUTHPROTO CHAP MSOFTv2
Sep 10 12:53:39 stat mpd: [L-1] LCP: state change Ack-Sent --> Opened
Sep 10 12:53:39 stat mpd: [L-1] LCP: auth: peer wants nothing, I want CHAP
Sep 10 12:53:39 stat mpd: [L-1] CHAP: sending CHALLENGE #1 len: 21
Sep 10 12:53:39 stat mpd: [L-1] LCP: LayerUp
Sep 10 12:53:39 stat mpd: [L-1] LCP: rec'd Ident #2 (Opened)
Sep 10 12:53:39 stat mpd: [L-1] MESG: MSRASV5.10
Sep 10 12:53:39 stat mpd: [L-1] LCP: rec'd Ident #3 (Opened)
Sep 10 12:53:39 stat mpd: [L-1] MESG: MSRAS-0-2-10-9
Sep 10 12:53:39 stat mpd: [L-1] CHAP: rec'd RESPONSE #1 len: 58
Sep 10 12:53:39 stat mpd: [L-1] Name: "test"
Sep 10 12:53:39 stat mpd: [L-1] AUTH: Trying RADIUS
Sep 10 12:53:39 stat mpd: [L-1] RADIUS: Authenticating user 'test'
Sep 10 12:53:39 stat mpd: [L-1] RADIUS: Rec'd RAD_ACCESS_ACCEPT for user 'test'
Sep 10 12:53:39 stat mpd: [L-1] AUTH: RADIUS returned: authenticated
Sep 10 12:53:39 stat mpd: [L-1] CHAP: Auth return status: authenticated
Sep 10 12:53:39 stat mpd: [L-1] CHAP: Reply message: S=BCBA3AAE46EB1687B4CF84117D1655859CFA3612
Sep 10 12:53:39 stat mpd: [L-1] CHAP: sending SUCCESS #1 len: 46
Sep 10 12:53:39 stat mpd: [L-1] LCP: authorization successful
Sep 10 12:53:39 stat mpd: [L-1] Link: Matched action 'bundle "B" ""'
Sep 10 12:53:39 stat mpd: [L-1] Creating new bundle using template "B".
Sep 10 12:53:39 stat mpd: [B-1] Bundle: Interface ng0 created
Sep 10 12:53:39 stat mpd: [L-1] Link: Join bundle "B-1"
Sep 10 12:53:39 stat mpd: [B-1] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Sep 10 12:53:39 stat mpd: [B-1] IPCP: Open event
Sep 10 12:53:39 stat mpd: [B-1] IPCP: state change Initial --> Starting
Sep 10 12:53:39 stat mpd: [B-1] IPCP: LayerStart
Sep 10 12:53:39 stat mpd: [B-1] CCP: Open event
Sep 10 12:53:39 stat mpd: [B-1] CCP: state change Initial --> Starting
Sep 10 12:53:39 stat mpd: [B-1] CCP: LayerStart
Sep 10 12:53:39 stat mpd: [B-1] IPCP: Up event
Sep 10 12:53:39 stat mpd: [B-1] IPCP: state change Starting --> Req-Sent
Sep 10 12:53:39 stat mpd: [B-1] IPCP: SendConfigReq #1
Sep 10 12:53:39 stat mpd: [B-1] IPADDR 192.168.0.10
Sep 10 12:53:39 stat mpd: [B-1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Sep 10 12:53:39 stat mpd: [B-1] CCP: Up event
Sep 10 12:53:39 stat mpd: [B-1] CCP: state change Starting --> Req-Sent
Sep 10 12:53:39 stat mpd: [B-1] CCP: SendConfigReq #1
Sep 10 12:53:39 stat mpd: [B-1] IPCP: rec'd Configure Reject #1 (Req-Sent)
Sep 10 12:53:39 stat mpd: [B-1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Sep 10 12:53:39 stat mpd: [B-1] IPCP: SendConfigReq #2
Sep 10 12:53:39 stat mpd: [B-1] IPADDR 192.168.0.10
Sep 10 12:53:39 stat mpd: [B-1] CCP: rec'd Configure Ack #1 (Req-Sent)
Sep 10 12:53:39 stat mpd: [B-1] CCP: state change Req-Sent --> Ack-Rcvd
Sep 10 12:53:39 stat mpd: [L-1] RADIUS: Accounting user 'test' (Type: 1)
Sep 10 12:53:39 stat mpd: [B-1] IPCP: rec'd Configure Ack #2 (Req-Sent)
Sep 10 12:53:39 stat mpd: [B-1] IPADDR 192.168.0.10
Sep 10 12:53:39 stat mpd: [B-1] IPCP: state change Req-Sent --> Ack-Rcvd
Sep 10 12:53:39 stat mpd: [L-1] RADIUS: Rec'd RAD_ACCOUNTING_RESPONSE for user 'test'
Sep 10 12:53:41 stat mpd: [B-1] IPCP: rec'd Configure Request #6 (Ack-Rcvd)
Sep 10 12:53:41 stat mpd: [B-1] IPADDR 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] NAKing with 10.10.1.20
Sep 10 12:53:41 stat mpd: [B-1] PRIDNS 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] NAKing with 192.168.0.10
Sep 10 12:53:41 stat mpd: [B-1] PRINBNS 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] SECDNS 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] SECNBNS 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] IPCP: SendConfigRej #6
Sep 10 12:53:41 stat mpd: [B-1] PRINBNS 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] SECDNS 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] SECNBNS 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] CCP: rec'd Configure Request #7 (Ack-Rcvd)
Sep 10 12:53:41 stat mpd: [B-1] MPPC
Sep 10 12:53:41 stat mpd: [B-1] 0x01000001:MPPC, stateless
Sep 10 12:53:41 stat mpd: [B-1] CCP: SendConfigRej #7
Sep 10 12:53:41 stat mpd: [B-1] MPPC
Sep 10 12:53:41 stat mpd: [B-1] 0x01000001:MPPC, stateless
Sep 10 12:53:41 stat mpd: [B-1] IPCP: rec'd Configure Request #8 (Ack-Rcvd)
Sep 10 12:53:41 stat mpd: [B-1] IPADDR 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] NAKing with 10.10.1.20
Sep 10 12:53:41 stat mpd: [B-1] PRIDNS 0.0.0.0
Sep 10 12:53:41 stat mpd: [B-1] NAKing with 192.168.0.10
Sep 10 12:53:41 stat mpd: [B-1] IPCP: SendConfigNak #8
Sep 10 12:53:41 stat mpd: [B-1] IPADDR 10.10.1.20
Sep 10 12:53:41 stat mpd: [B-1] PRIDNS 192.168.0.10
Sep 10 12:53:41 stat mpd: [B-1] CCP: rec'd Terminate Request #9 (Ack-Rcvd)
Sep 10 12:53:41 stat mpd: [B-1] CCP: state change Ack-Rcvd --> Req-Sent
Sep 10 12:53:41 stat mpd: [B-1] CCP: SendTerminateAck #2
Sep 10 12:53:41 stat mpd: [B-1] IPCP: rec'd Configure Request #10 (Ack-Rcvd)
Sep 10 12:53:41 stat mpd: [B-1] IPADDR 10.10.1.20
Sep 10 12:53:41 stat mpd: [B-1] 10.10.1.20 is OK
Sep 10 12:53:41 stat mpd: [B-1] PRIDNS 192.168.0.10
Sep 10 12:53:41 stat mpd: [B-1] IPCP: SendConfigAck #10
Sep 10 12:53:41 stat mpd: [B-1] IPADDR 10.10.1.20
Sep 10 12:53:41 stat mpd: [B-1] PRIDNS 192.168.0.10
Sep 10 12:53:41 stat mpd: [B-1] IPCP: state change Ack-Rcvd --> Opened
Sep 10 12:53:41 stat mpd: [B-1] IPCP: LayerUp
Sep 10 12:53:41 stat mpd: [B-1] 192.168.0.10 -> 10.10.1.20
Sep 10 12:53:41 stat mpd: [B-1] IFACE: No interface to proxy arp on for 10.10.1.20
Sep 10 12:53:41 stat mpd: [B-1] IFACE: Up event
Sep 10 12:53:41 stat mpd: [B-1] CCP: SendConfigReq #3
Sep 10 12:53:43 stat mpd: [B-1] CCP: SendConfigReq #4
Sep 10 12:53:45 stat mpd: [B-1] CCP: rec'd Terminate Request #11 (Req-Sent)
Sep 10 12:53:45 stat mpd: [B-1] CCP: SendTerminateAck #5
Sep 10 12:53:45 stat mpd: [B-1] CCP: SendConfigReq #6
Sep 10 12:53:48 stat mpd: [B-1] CCP: SendConfigReq #7
Sep 10 12:53:50 stat mpd: [B-1] CCP: SendConfigReq #8
Sep 10 12:53:50 stat mpd: [B-1] CCP: rec'd Terminate Ack #8 (Req-Sent)
Sep 10 12:53:52 stat mpd: [B-1] CCP: SendConfigReq #9
Sep 10 12:53:52 stat mpd: [B-1] CCP: rec'd Terminate Ack #9 (Req-Sent)
Sep 10 12:53:54 stat mpd: [B-1] CCP: SendConfigReq #10
Sep 10 12:53:54 stat mpd: [B-1] CCP: rec'd Terminate Ack #10 (Req-Sent)
Sep 10 12:53:56 stat mpd: [B-1] CCP: SendConfigReq #11
Sep 10 12:53:56 stat mpd: [B-1] CCP: rec'd Terminate Ack #11 (Req-Sent)
Sep 10 12:53:58 stat mpd: [B-1] CCP: SendConfigReq #12
Sep 10 12:53:58 stat mpd: [B-1] CCP: rec'd Terminate Ack #12 (Req-Sent)
Sep 10 12:54:00 stat mpd: [B-1] CCP: SendConfigReq #13
Sep 10 12:54:00 stat mpd: [B-1] CCP: rec'd Terminate Ack #13 (Req-Sent)
Sep 10 12:54:02 stat mpd: [B-1] CCP: parameter negotiation failed
Sep 10 12:54:02 stat mpd: [B-1] CCP: state change Req-Sent --> Stopped
Sep 10 12:54:02 stat mpd: [B-1] CCP: LayerFinish
Sep 10 12:57:43 stat mpd: [L-1] LCP: rec'd Terminate Request #12 (Opened)
Sep 10 12:57:43 stat mpd: [L-1] LCP: state change Opened --> Stopping
Sep 10 12:57:43 stat mpd: [L-1] Link: Leave bundle "B-1"
Sep 10 12:57:43 stat mpd: [B-1] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Sep 10 12:57:43 stat mpd: [B-1] IPCP: Close event
Sep 10 12:57:43 stat mpd: [B-1] IPCP: state change Opened --> Closing
Sep 10 12:57:43 stat mpd: [B-1] IPCP: SendTerminateReq #3
Sep 10 12:57:43 stat mpd: [B-1] IPCP: LayerDown
Sep 10 12:57:43 stat mpd: [B-1] IFACE: Down event
Sep 10 12:57:43 stat mpd: [B-1] CCP: Close event
Sep 10 12:57:43 stat mpd: [B-1] CCP: state change Stopped --> Closed
Sep 10 12:57:43 stat mpd: [B-1] IPCP: Down event
Sep 10 12:57:43 stat mpd: [B-1] IPCP: LayerFinish
Sep 10 12:57:43 stat mpd: [B-1] Bundle: No NCPs left. Closing links...
Sep 10 12:57:43 stat mpd: [B-1] IPCP: state change Closing --> Initial
Sep 10 12:57:43 stat mpd: [B-1] CCP: Down event
Sep 10 12:57:43 stat mpd: [B-1] CCP: state change Closed --> Initial
Sep 10 12:57:43 stat mpd: [B-1] Bundle: Shutdown
Sep 10 12:57:43 stat mpd: [L-1] LCP: SendTerminateAck #4
Sep 10 12:57:43 stat mpd: [L-1] LCP: LayerDown
Sep 10 12:57:43 stat mpd: [L-1] RADIUS: Accounting user 'test' (Type: 2)
Sep 10 12:57:43 stat mpd: [L-1] RADIUS: Rec'd RAD_ACCOUNTING_RESPONSE for user 'test'
Sep 10 12:57:43 stat mpd: [L-1] rec'd proto IP during terminate phase
Sep 10 12:57:45 stat mpd: [L-1] rec'd proto IP during terminate phase
Sep 10 12:57:45 stat mpd: [L-1] LCP: state change Stopping --> Stopped
Sep 10 12:57:45 stat mpd: [L-1] LCP: LayerFinish
Sep 10 12:57:45 stat mpd: [L-1] PPTP call terminated
Sep 10 12:57:45 stat mpd: [L-1] Link: DOWN event
Sep 10 12:57:45 stat mpd: [L-1] LCP: Close event
Sep 10 12:57:45 stat mpd: [L-1] LCP: state change Stopped --> Closed
Sep 10 12:57:45 stat mpd: [L-1] LCP: Down event
Sep 10 12:57:45 stat mpd: [L-1] LCP: state change Closed --> Initial
Sep 10 12:57:45 stat mpd: [L-1] Link: SHUTDOWN event
Sep 10 12:57:45 stat mpd: [L-1] Link: Shutdown
Sep 10 13:42:30 stat mpd: [L-1] Accepting PPTP connection
Sep 10 13:42:30 stat mpd: [L-1] Link: OPEN event
Sep 10 13:42:30 stat mpd: [L-1] LCP: Open event
Радиус
?Debug : Sep 10 12:52:33 AuthServer: User <test> connecting
?Debug : Sep 10 12:52:33 AuthServer: Session for sessionid <test> not found in <127.0.0.1> cache
?Debug : Sep 10 12:52:33 RADIUS DBA: Info for login <test> found. type <1>
?Debug : Sep 10 12:52:33 AuthServer: Auth scheme: MS-CHAPv2
?Debug : Sep 10 12:52:33 AuthServer: MS-CHAPv2: Authorized user <test>
?Debug : Sep 10 12:52:33 AuthServer: MS-CHAPv2: MPPE Keys send
Warn : Sep 10 12:52:33 AuthServer: Unable to get Account Data: No such file or directory
?Debug : Sep 10 12:52:33 AuthServer: Calling fill radius attributes for NAS. Attr storage size <0>
Notice: Sep 10 12:52:33 AuthServer: Login incorrect <test> from NAS <127.0.0.1> CLID <> Calling-station <10.10.0.9>
Notice: Sep 10 12:52:33 AuthServer: Authorization failed for user <test>
?Debug : Sep 10 12:52:33 AuthServer: Auth reply: RPacket:
Code: 3; ID: 99
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 9; Attr: 103>[19]: 683332332d72657475726e2d636f64653d2d31
<Vendor: 311; Attr: 7>[4]: 00000001
<Vendor: 311; Attr: 8>[4]: 00000006
<Vendor: 311; Attr: 16>[34]: 8a62e3c6f8abc5ca25a20eb945d48e825e57623c3b3ad599f7a9a86060dd4c1e73af
<Vendor: 311; Attr: 17>[34]: 8f1e1be50858a5b3a92caa8073aaf539c51a46ea15225e8c81517eb5cea0987eabfb
<Vendor: 311; Attr: 26>[43]: 81533d34333535383345413436303836343733443433453336343246424245353046333442313345443735
?Debug : Sep 10 12:52:33 RADIUS Packet: raw data constructed! size <229>
?Debug : Sep 10 12:52:33 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 10 12:52:33 RadiusSocket: RADIUS raw data sent
?Debug : Sep 10 12:52:33 AuthServer: Next...
?Trace : Sep 10 12:52:33 AuthServer: Process loop step
?Debug : Sep 10 12:52:33 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 10 12:52:45 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 10 12:52:45 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 10 12:52:45 RADIUS Packet: Size <293>; HDR.Size <293>
?Debug : Sep 10 12:52:45 AcctServer: Recv...
?Debug : Sep 10 12:52:45 AcctServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 4; ID: 205
<Vendor: 0; Attr: 1>[4]: 6c697961
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000001
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a0a0102
<Vendor: 0; Attr: 9>[4]: ffffffff
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[13]: 3139322e3136382e302e313031
<Vendor: 0; Attr: 32>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 0; Attr: 40>[4]: 00000003
<Vendor: 0; Attr: 42>[4]: 000fde4d
<Vendor: 0; Attr: 43>[4]: 00352731
<Vendor: 0; Attr: 44>[11]: 343130343331392d4c2d31
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 46>[4]: 00001161
<Vendor: 0; Attr: 47>[4]: 0000113a
<Vendor: 0; Attr: 48>[4]: 00001238
<Vendor: 0; Attr: 50>[11]: 343130343331392d422d31
<Vendor: 0; Attr: 51>[4]: 00000001
<Vendor: 0; Attr: 52>[4]: 00000000
<Vendor: 0; Attr: 53>[4]: 00000000
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[13]: 3139322e3136382e302e313031
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 91>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 12341; Attr: 12>[3]: 4c2d31
<Vendor: 12341; Attr: 13>[3]: 422d31
<Vendor: 12341; Attr: 14>[3]: 6e6730
<Vendor: 12341; Attr: 15>[4]: 00000006
?Debug : Sep 10 12:52:45 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 10 12:52:45 AcctServer: Acct packet with session ID: 4104319-L-1
?Debug : Sep 10 12:52:45 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 10 12:52:45 AcctServer: Acct-Interim-Update packet
?Debug : Sep 10 12:52:45 AcctServer: Acct-Start: User <liya>
?Debug : Sep 10 12:52:45 AcctServer: Updating session <4104319-L-1> input/output octets <1039949>/<3483441> session time <4449>
?Debug : Sep 10 12:52:45 RADIUS DBA: Interim updating session <4104319-L-1> with timestamp <1284108765>
?Debug : Sep 10 12:52:45 RADIUS Stream[plugin]: edit log id <9>
?Debug : Sep 10 12:52:45 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 205
?Debug : Sep 10 12:52:45 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 10 12:52:45 RadiusSocket: RADIUS raw data sent
?Debug : Sep 10 12:52:45 AcctServer: Next...
?Debug : Sep 10 12:52:45 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 10 12:52:46 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 10 12:52:46 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 10 12:52:46 RADIUS Packet: Size <295>; HDR.Size <295>
?Debug : Sep 10 12:52:46 AcctServer: Recv...
?Debug : Sep 10 12:52:46 AcctServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 4; ID: 23
<Vendor: 0; Attr: 1>[6]: 6e6174616c69
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000002
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a0a0108
<Vendor: 0; Attr: 9>[4]: ffffffff
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[13]: 3139322e3136382e302e313730
<Vendor: 0; Attr: 32>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 0; Attr: 40>[4]: 00000003
<Vendor: 0; Attr: 42>[4]: 000d6ca8
<Vendor: 0; Attr: 43>[4]: 00538a1a
<Vendor: 0; Attr: 44>[11]: 343039363838392d4c2d32
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 46>[4]: 00002e67
<Vendor: 0; Attr: 47>[4]: 000020e7
<Vendor: 0; Attr: 48>[4]: 00002370
<Vendor: 0; Attr: 50>[11]: 343039363839302d422d32
<Vendor: 0; Attr: 51>[4]: 00000001
<Vendor: 0; Attr: 52>[4]: 00000000
<Vendor: 0; Attr: 53>[4]: 00000000
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[13]: 3139322e3136382e302e313730
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 91>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 12341; Attr: 12>[3]: 4c2d32
<Vendor: 12341; Attr: 13>[3]: 422d32
<Vendor: 12341; Attr: 14>[3]: 6e6731
<Vendor: 12341; Attr: 15>[4]: 00000007
?Debug : Sep 10 12:52:46 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 10 12:52:46 AcctServer: Acct packet with session ID: 4096889-L-2
?Debug : Sep 10 12:52:46 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 10 12:52:46 AcctServer: Acct-Interim-Update packet
?Debug : Sep 10 12:52:46 AcctServer: Acct-Start: User <natali>
?Debug : Sep 10 12:52:46 AcctServer: Updating session <4096889-L-2> input/output octets <879784>/<5474842> session time <11879>
?Debug : Sep 10 12:52:46 RADIUS DBA: Interim updating session <4096889-L-2> with timestamp <1284108766>
?Debug : Sep 10 12:52:46 RADIUS Stream[plugin]: edit log id <6>
?Debug : Sep 10 12:52:46 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 23
?Debug : Sep 10 12:52:46 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 10 12:52:46 RadiusSocket: RADIUS raw data sent
?Debug : Sep 10 12:52:46 AcctServer: Next...
?Debug : Sep 10 12:52:46 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 10 12:52:54 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 10 12:52:54 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 10 12:52:54 RADIUS Packet: Size <266>; HDR.Size <266>
?Debug : Sep 10 12:52:54 AuthServer: Recv...
?Debug : Sep 10 12:52:54 AuthServer: Packet from NAS <127.0.0.1>
?Debug : Sep 10 12:52:54 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 10 12:52:54 AuthServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 1; ID: 248
<Vendor: 0; Attr: 1>[4]: 74657374
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000004
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[9]: 31302e31302e302e39
<Vendor: 0; Attr: 32>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 0; Attr: 44>[11]: 343130383737342d4c2d34
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[9]: 31302e31302e302e39
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 80>[16]: b7e3cf31e059dbfb1dd4a8e80ba1e6fc
<Vendor: 0; Attr: 91>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 311; Attr: 11>[16]: bb1e68ae4a9bdfa437f8718917b01169
<Vendor: 311; Attr: 25>[50]: 0100e3292f6f96c282ddda406035f30eff670000000000000000b3aa21101d0212a6a73aebf77ee27fb9045032f630c7ac02
<Vendor: 12341; Attr: 12>[3]: 4c2d34
?Debug : Sep 10 12:52:54 AuthServer: User <test> connecting
?Debug : Sep 10 12:52:54 AuthServer: Session for sessionid <test> not found in <127.0.0.1> cache
?Debug : Sep 10 12:52:54 RADIUS DBA: Info for login <test> found. type <1>
?Debug : Sep 10 12:52:54 AuthServer: Auth scheme: MS-CHAPv2
?Debug : Sep 10 12:52:54 AuthServer: MS-CHAPv2: Authorized user <test>
?Debug : Sep 10 12:52:54 AuthServer: MS-CHAPv2: MPPE Keys send
Warn : Sep 10 12:52:54 AuthServer: Unable to get Account Data: No such file or directory
?Debug : Sep 10 12:52:54 AuthServer: Calling fill radius attributes for NAS. Attr storage size <0>
Notice: Sep 10 12:52:54 AuthServer: Login incorrect <test> from NAS <127.0.0.1> CLID <> Calling-station <10.10.0.9>
Notice: Sep 10 12:52:54 AuthServer: Authorization failed for user <test>
?Debug : Sep 10 12:52:54 AuthServer: Auth reply: RPacket:
Code: 3; ID: 248
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 9; Attr: 103>[19]: 683332332d72657475726e2d636f64653d2d31
<Vendor: 311; Attr: 7>[4]: 00000001
<Vendor: 311; Attr: 8>[4]: 00000006
<Vendor: 311; Attr: 16>[34]: 809419ea8ce6f3ce92f002b000cc133659c9c7e71e86cfc038fc2dde00c8676584e4
<Vendor: 311; Attr: 17>[34]: 81f8f639b6a890972b5820f0ae211e2c88d4cf79553902db72cd997a593dcb6c193c
<Vendor: 311; Attr: 26>[43]: 81533d38444243323242343636354231384244423145334232393138413843393633393042304335393231
?Debug : Sep 10 12:52:54 RADIUS Packet: raw data constructed! size <229>
?Debug : Sep 10 12:52:54 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 10 12:52:54 RadiusSocket: RADIUS raw data sent
?Debug : Sep 10 12:52:54 AuthServer: Next...
?Trace : Sep 10 12:52:54 AuthServer: Process loop step
?Debug : Sep 10 12:52:54 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 10 12:52:57 RADIUS DBA: Correctly interim updated session <6> found. Leave untouched.
?Debug : Sep 10 12:52:57 RADIUS DBA: Correctly interim updated session <8> found. Leave untouched.
?Debug : Sep 10 12:52:57 RADIUS DBA: Correctly interim updated session <9> found. Leave untouched.
?Debug : Sep 10 12:52:58 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 10 12:53:00 RADIUS Stream[plugin]: Account <6> with balance <706.737>
?Debug : Sep 10 12:53:00 RADIUS Stream[plugin]: Account <2> with balance <0.000>
?Debug : Sep 10 12:53:00 RADIUS Stream[plugin]: Account <2> with balance <0.000>
?Debug : Sep 10 12:53:01 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 10 12:53:01 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 10 12:53:01 RADIUS Packet: Size <301>; HDR.Size <301>
?Debug : Sep 10 12:53:01 AcctServer: Recv...
?Debug : Sep 10 12:53:01 AcctServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 4; ID: 234
<Vendor: 0; Attr: 1>[6]: 6e6174616c69
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000002
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a0a0108
<Vendor: 0; Attr: 9>[4]: ffffffff
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[13]: 3139322e3136382e302e313730
<Vendor: 0; Attr: 32>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 0; Attr: 40>[4]: 00000002
<Vendor: 0; Attr: 42>[4]: 000d6fb6
<Vendor: 0; Attr: 43>[4]: 00538a20
<Vendor: 0; Attr: 44>[11]: 343039363838392d4c2d32
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 46>[4]: 00002e76
<Vendor: 0; Attr: 47>[4]: 000020f0
<Vendor: 0; Attr: 48>[4]: 00002371
<Vendor: 0; Attr: 49>[4]: 00000007
<Vendor: 0; Attr: 50>[11]: 343039363839302d422d32
<Vendor: 0; Attr: 51>[4]: 00000001
<Vendor: 0; Attr: 52>[4]: 00000000
<Vendor: 0; Attr: 53>[4]: 00000000
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[13]: 3139322e3136382e302e313730
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 91>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 12341; Attr: 12>[3]: 4c2d32
<Vendor: 12341; Attr: 13>[3]: 422d32
<Vendor: 12341; Attr: 14>[3]: 6e6731
<Vendor: 12341; Attr: 15>[4]: 00000007
?Debug : Sep 10 12:53:01 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 10 12:53:01 AcctServer: Acct packet with session ID: 4096889-L-2
?Debug : Sep 10 12:53:01 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 10 12:53:01 AcctServer: Acct-Stop packet
?Debug : Sep 10 12:53:01 RADIUS DBA: Session erase ... login type <1>
?Debug : Sep 10 12:53:01 RADIUS DBA: login type login_pool or login_named_pool
?Debug : Sep 10 12:53:01 RADIUS IPPool: Released <a0a0108>
?Debug : Sep 10 12:53:01 RADIUS Stream[plugin]: finish log id <6>
?Debug : Sep 10 12:53:01 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 234
?Debug : Sep 10 12:53:01 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 10 12:53:01 RadiusSocket: RADIUS raw data sent
?Debug : Sep 10 12:53:01 AcctServer: Next...
?Debug : Sep 10 12:53:01 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 10 12:53:01 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 10 12:53:01 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 10 12:53:01 RADIUS Packet: Size <300>; HDR.Size <300>
?Debug : Sep 10 12:53:01 AcctServer: Recv...
?Debug : Sep 10 12:53:01 AcctServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 4; ID: 74
<Vendor: 0; Attr: 1>[5]: 7665676173
...................
?Debug : Sep 10 12:53:01 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 10 12:53:01 RadiusSocket: RADIUS raw data sent
?Debug : Sep 10 12:53:01 AcctServer: Next...
?Debug : Sep 10 12:53:01 RadiusSocket: Waiting for RADIUS raw data
Info : Sep 10 12:53:22 RADIUS Tarif: Created...
Notice: Sep 10 12:53:22 RADIUS Config: Processing config file: /netup/utm5/radius5.cfg
?Debug : Sep 10 12:53:22 RADIUS Config: Using classic BaseTelephony
?Trace : Sep 10 12:53:22 RADIUS DBA: New state: ds_failed
Info : Sep 10 12:53:22 StreamManager: Registering message handlers..
Info : Sep 10 12:53:22 StreamManager: ID <0x2001> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2002> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2003> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2004> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2005> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2006> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2007> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2008> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2009> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x200a> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x200b> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x200c> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x200d> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x200e> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x200f> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2010> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2011> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2012> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2013> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2014> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2015> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2016> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2019> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x201a> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x201b> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x201c> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x201e> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x201f> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2020> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2021> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2022> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2023> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x202c> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x202d> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x202e> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x202f> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2030> handler <0x2862e080>
Info : Sep 10 12:53:22 StreamManager: ID <0x2031> handler <0x2862e080>
Info : Sep 10 12:53:22 RadiusSocket: Listening on 0.0.0.0:1812
?Trace : Sep 10 12:53:22 AuthServer: Entering process loop
Info : Sep 10 12:53:22 RadiusSocket: Listening on 0.0.0.0:1813
Info : Sep 10 12:53:22 StreamConnection: Connection thread started. Peer 127.0.0.1:12758
?Debug : Sep 10 12:53:22 StreamConnection: Connection using TCP socket
?Debug : Sep 10 12:53:22 StreamConnection: System message recived
?Debug : Sep 10 12:53:22 StreamConnection: Challenge response sent
?Debug : Sep 10 12:53:22 StreamConnection: System message recived
Info : Sep 10 12:53:22 StreamConnection: Connection successfully authorized, user id <-2>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: dialup features received
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: telephony features received
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: telephony features received
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Got license info..
?Debug : Sep 10 12:53:22 RADIUS DBA: Updating Named Pool: user_class
?Debug : Sep 10 12:53:22 RADIUS DBA: New Named Pool inserted: user_class
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 10/1/14/11. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 11/2/15/11. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 12/3/16/11. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 13/5/17/11. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 15/6/19/9. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 16/7/21/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 17/8/22/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 18/9/23/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 19/10/24/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 20/11/25/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 21/12/26/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 22/13/27/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 23/14/28/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 24/15/29/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 25/16/30/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 26/17/31/12. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 27/18/32/11. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 28/19/33/11. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 29/9/34/11. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 31/10/36/11. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 32/21/37/13. 1 nodes
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP-traffic service <1> received
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Vendor <1234> attr <7> value size <26>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Vendor <1234> attr <7> value size <27>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP-traffic service <3> received
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP-traffic service <9> received
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP-traffic service <11> received
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Vendor <12341> attr <7> value size <27>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Vendor <12341> attr <7> value size <28>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP-traffic service <12> received
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Vendor <12341> attr <7> value size <28>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Vendor <12341> attr <7> value size <26>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: IP-traffic service <13> received
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
Info : Sep 10 12:53:22 RADIUS DBA: Inserting NAS. Data size <0>
Info : Sep 10 12:53:22 RADIUS DBA: Inserting NAS result. Data size <0>
Info : Sep 10 12:53:22 NASCache<127.0.0.1>: Created...
Info : Sep 10 12:53:22 RADIUS Stream[plugin]: NAS <127.0.0.1> added/modified
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: TimeRange <1>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: DialUp service <5>
Info : Sep 10 12:53:22 RADIUS DBA: Starting directions sort...
Info : Sep 10 12:53:22 RADIUS DBA: Finished directions sort...
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <1> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <2> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <3> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <5> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <6> with balance <706.737>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <7> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <8> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <9> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <10> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <11> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <12> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <13> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Account <14> with balance <0.000>
?Debug : Sep 10 12:53:22 RADIUS DBA: Flushing REALM list
?Debug : Sep 10 12:53:22 RADIUS Config: RADIUS server ready to serve requests
?Trace : Sep 10 12:53:22 RADIUS DBA: New state: ds_up
?Trace : Sep 10 12:53:22 AuthServer: Process loop step
?Debug : Sep 10 12:53:22 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 10 12:53:22 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 10 12:53:22 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 10 12:53:39 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 10 12:53:39 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 10 12:53:39 RADIUS Packet: Size <266>; HDR.Size <266>
?Debug : Sep 10 12:53:39 AuthServer: Recv...
?Debug : Sep 10 12:53:39 AuthServer: Packet from NAS <127.0.0.1>
?Debug : Sep 10 12:53:39 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 10 12:53:39 AuthServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 1; ID: 96
<Vendor: 0; Attr: 1>[4]: 74657374
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000001
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[9]: 31302e31302e302e39
<Vendor: 0; Attr: 32>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 0; Attr: 44>[11]: 343130383831392d4c2d31
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[9]: 31302e31302e302e39
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 80>[16]: 62ca3ea4d71b6dab1bde8778ad7263d0
<Vendor: 0; Attr: 91>[16]: 737461742e696e7465722e6c6f63616c
<Vendor: 311; Attr: 11>[16]: bb1e68292de1c3efc9359b155e9d1933
<Vendor: 311; Attr: 25>[50]: 01009dfe9f16da8aedbc06dc1ff97a817fad0000000000000000f2db0e138b5a0f99bf689bb3da68dc42d9d92aefe97ef4fc
<Vendor: 12341; Attr: 12>[3]: 4c2d31
?Debug : Sep 10 12:53
slash
Сообщения: 33 Зарегистрирован: Пн янв 25, 2010 17:02
Сообщение
slash Вт сен 14, 2010 15:29
Ни у кого такой проблемы небыло?
kaN5300
Сообщения: 480 Зарегистрирован: Пт янв 21, 2005 17:27Откуда: Ыукзгрщм
Контактная информация:
Сообщение
kaN5300 Ср сен 15, 2010 08:58
MPD врядли здесь причем. Если один лишь только радиус перезагружать, помогает? Какая вобще конфигурация системы? Все сервисы на одной машине?
slash
Сообщения: 33 Зарегистрирован: Пн янв 25, 2010 17:02
Сообщение
slash Сб сен 18, 2010 11:27
kaN5300 писал(а): MPD врядли здесь причем. Если один лишь только радиус перезагружать, помогает? Какая вобще конфигурация системы? Все сервисы на одной машине?
Да все сервисы на одной машине.
kaN5300
Сообщения: 480 Зарегистрирован: Пт янв 21, 2005 17:27Откуда: Ыукзгрщм
Контактная информация:
Сообщение
kaN5300 Сб сен 18, 2010 13:54
Если один лишь только радиус перезагружать, помогает?
slash
Сообщения: 33 Зарегистрирован: Пн янв 25, 2010 17:02
Сообщение
slash Пн сен 20, 2010 08:58
kaN5300 писал(а): Если один лишь только радиус перезагружать, помогает?
Да помогает, после рестарта утм радиуса, новый пользователь может нормально, соединиться.
А в чем может быть проблема то у радиуса? можно как нить сделать, чтоб после ввода нового пользователя, не надо было рестартовать радиус?
kaN5300
Сообщения: 480 Зарегистрирован: Пт янв 21, 2005 17:27Откуда: Ыукзгрщм
Контактная информация:
Сообщение
kaN5300 Пн сен 20, 2010 09:02
Вобще, похоже на то, что радиус теряет соединение с ядром через какое-то время. Посмотрите в сторону настроек тайм-аутов, к-ва попыток реконнекта радиуса к ядру и т.д. И почитайте логи радиуса, возможно там он и будет писать что не может подключиться к кору.
slash
Сообщения: 33 Зарегистрирован: Пн янв 25, 2010 17:02
Сообщение
slash Пн сен 20, 2010 09:33
kaN5300 писал(а): Вобще, похоже на то, что радиус теряет соединение с ядром через какое-то время. Посмотрите в сторону настроек тайм-аутов, к-ва попыток реконнекта радиуса к ядру и т.д. И почитайте логи радиуса, возможно там он и будет писать что не может подключиться к кору.
Да но это происходит лишь в том случае, если я завожу нового пользователя в биллинге. Если же не заводить пользователя, то норма все работает.
slash
Сообщения: 33 Зарегистрирован: Пн янв 25, 2010 17:02
Сообщение
slash Пн сен 20, 2010 09:58
Вот лог радиуса
до ввода нового пользователя в биллинг и после рестарта радиуса
Код: Выделить всё
?Debug : Sep 20 09:50:26 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:50:26 AcctServer: Acct packet with session ID: 4960900-L-1
?Debug : Sep 20 09:50:26 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:50:26 AcctServer: Acct-Interim-Update packet
?Debug : Sep 20 09:50:26 AcctServer: Acct-Start: User <ludmila>
?Debug : Sep 20 09:50:26 AcctServer: Updating session <4960900-L-1> input/output octets <6607>/<684> session time <928>
?Debug : Sep 20 09:50:26 RADIUS DBA: Interim updating session <4960900-L-1> with timestamp <1284961826>
?Debug : Sep 20 09:50:26 RADIUS Stream[plugin]: edit log id <1>
?Debug : Sep 20 09:50:26 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 31
?Debug : Sep 20 09:50:26 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 20 09:50:26 RadiusSocket: RADIUS raw data sent
?Debug : Sep 20 09:50:26 AcctServer: Next...
?Debug : Sep 20 09:50:26 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 20 09:50:41 RADIUS DBA: Correctly interim updated session <1> found. Leave untouched.
?Debug : Sep 20 09:50:42 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 20 09:51:12 RADIUS DBA: Correctly interim updated session <1> found. Leave untouched.
?Debug : Sep 20 09:51:12 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 20 09:51:32 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 20 09:51:32 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 20 09:51:32 RADIUS Packet: Size <294>; HDR.Size <294>
?Debug : Sep 20 09:51:32 AcctServer: Recv...
?Debug : Sep 20 09:51:32 AcctServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 4; ID: 126
<Vendor: 0; Attr: 1>[7]: 6c75646d696c61
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000001
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a0a010c
<Vendor: 0; Attr: 9>[4]: ffffffff
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[12]: 3139322e3136382e302e3938
<Vendor: 0; Attr: 32>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 0; Attr: 40>[4]: 00000003
<Vendor: 0; Attr: 42>[4]: 00001ba6
<Vendor: 0; Attr: 43>[4]: 000002d0
<Vendor: 0; Attr: 44>[11]: 343936303930302d4c2d31
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 46>[4]: 000003e2
<Vendor: 0; Attr: 47>[4]: 0000007b
<Vendor: 0; Attr: 48>[4]: 00000040
<Vendor: 0; Attr: 50>[11]: 343936303930312d422d31
<Vendor: 0; Attr: 51>[4]: 00000001
<Vendor: 0; Attr: 52>[4]: 00000000
<Vendor: 0; Attr: 53>[4]: 00000000
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[12]: 3139322e3136382e302e3938
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 91>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 12341; Attr: 12>[3]: 4c2d31
<Vendor: 12341; Attr: 13>[3]: 422d31
<Vendor: 12341; Attr: 14>[3]: 6e6730
<Vendor: 12341; Attr: 15>[4]: 00000006
?Debug : Sep 20 09:51:32 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:51:32 AcctServer: Acct packet with session ID: 4960900-L-1
?Debug : Sep 20 09:51:32 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:51:32 AcctServer: Acct-Interim-Update packet
?Debug : Sep 20 09:51:32 AcctServer: Acct-Start: User <ludmila>
?Debug : Sep 20 09:51:32 AcctServer: Updating session <4960900-L-1> input/output octets <7078>/<720> session time <994>
?Debug : Sep 20 09:51:32 RADIUS DBA: Interim updating session <4960900-L-1> with timestamp <1284961892>
?Debug : Sep 20 09:51:32 RADIUS Stream[plugin]: edit log id <1>
?Debug : Sep 20 09:51:32 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 126
?Debug : Sep 20 09:51:32 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 20 09:51:32 RadiusSocket: RADIUS raw data sent
?Debug : Sep 20 09:51:32 AcctServer: Next...
?Debug : Sep 20 09:51:32 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 20 09:51:42 RADIUS DBA: Correctly interim updated session <1> found. Leave untouched.
?Debug : Sep 20 09:51:43 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 20 09:51:58 RADIUS Stream[plugin]: Account <6> with balance <350.671>
?Debug : Sep 20 09:51:59 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:51:59 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:51:59 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 33/22/38/13. 1 nodes
?Debug : Sep 20 09:52:13 RADIUS DBA: Correctly interim updated session <1> found. Leave untouched.
?Debug : Sep 20 09:52:14 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 20 09:52:17 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 20 09:52:17 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 20 09:52:17 RADIUS Packet: Size <271>; HDR.Size <271>
?Debug : Sep 20 09:52:17 AuthServer: Recv...
?Debug : Sep 20 09:52:17 AuthServer: Packet from NAS <127.0.0.1>
?Debug : Sep 20 09:52:17 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:52:17 AuthServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 1; ID: 229
<Vendor: 0; Attr: 1>[5]: 7573657231
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000002
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[11]: 3139322e3136382e302e35
<Vendor: 0; Attr: 32>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 0; Attr: 44>[11]: 343936313933372d4c2d32
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[11]: 3139322e3136382e302e35
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 80>[16]: 25b8a3d06bac1583e81a7dcbe32a3407
<Vendor: 0; Attr: 91>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 311; Attr: 11>[16]: bb1e68bc9fcf2fa0a2fb25623628dab0
<Vendor: 311; Attr: 25>[50]: 010065dd2a1244b76004a55a1950bc8a68910000000000000000f20a98b7336c9b598cb152299038d84380cf68205faa06ff
<Vendor: 12341; Attr: 12>[3]: 4c2d32
?Debug : Sep 20 09:52:17 AuthServer: User <user1> connecting
?Debug : Sep 20 09:52:17 AuthServer: Session for sessionid <user1> not found in <127.0.0.1> cache
?Debug : Sep 20 09:52:17 RADIUS DBA: Info for login <user1> found. type <1>
?Debug : Sep 20 09:52:17 AuthServer: Auth scheme: MS-CHAPv2
?Debug : Sep 20 09:52:17 AuthServer: MS-CHAPv2: Authorized user <user1>
?Debug : Sep 20 09:52:17 AuthServer: MS-CHAPv2: MPPE Keys send
Warn : Sep 20 09:52:17 AuthServer: Unable to get Account Data: No such file or directory
?Debug : Sep 20 09:52:17 AuthServer: Calling fill radius attributes for NAS. Attr storage size <0>
Notice: Sep 20 09:52:17 AuthServer: Login incorrect <user1> from NAS <127.0.0.1> CLID <> Calling-station <192.168.0.5>
Notice: Sep 20 09:52:17 AuthServer: Authorization failed for user <user1>
?Debug : Sep 20 09:52:17 AuthServer: Auth reply: RPacket:
Code: 3; ID: 229
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 9; Attr: 103>[19]: 683332332d72657475726e2d636f64653d2d31
<Vendor: 311; Attr: 7>[4]: 00000001
<Vendor: 311; Attr: 8>[4]: 00000006
<Vendor: 311; Attr: 16>[34]: 8ad71700c3ddde540d455ca97eaad9c4fbbcfac498c008e9b23e828639d6700fc52f
<Vendor: 311; Attr: 17>[34]: 841e42df8d4e971798eeff1dc1c42e208ddbe16386c023f91b5197f5cf3fa87af4a4
<Vendor: 311; Attr: 26>[43]: 81533d45333833314436443139354445443432383536323239443834303544463138423233444137423739
Вот после рестарта радиуса
Код: Выделить всё
?Debug : Sep 20 09:52:17 RADIUS Packet: raw data constructed! size <229>
?Debug : Sep 20 09:52:17 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 20 09:52:17 RadiusSocket: RADIUS raw data sent
?Debug : Sep 20 09:52:17 AuthServer: Next...
?Trace : Sep 20 09:52:17 AuthServer: Process loop step
?Debug : Sep 20 09:52:17 RadiusSocket: Waiting for RADIUS raw data
Info : Sep 20 09:52:36 RADIUS Tarif: Created...
Notice: Sep 20 09:52:36 RADIUS Config: Processing config file: /netup/utm5/radius5.cfg
?Debug : Sep 20 09:52:36 RADIUS Config: Using classic BaseTelephony
?Trace : Sep 20 09:52:36 RADIUS DBA: New state: ds_failed
Info : Sep 20 09:52:36 StreamManager: Registering message handlers..
Info : Sep 20 09:52:36 StreamManager: ID <0x2001> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2002> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2003> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2004> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2005> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2006> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2007> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2008> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2009> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x200a> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x200b> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x200c> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x200d> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x200e> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x200f> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2010> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2011> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2012> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2013> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2014> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2015> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2016> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2019> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x201a> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x201b> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x201c> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x201e> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x201f> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2020> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2021> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2022> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2023> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x202c> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x202d> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x202e> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x202f> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2030> handler <0x2862e080>
Info : Sep 20 09:52:36 StreamManager: ID <0x2031> handler <0x2862e080>
Info : Sep 20 09:52:36 RadiusSocket: Listening on 0.0.0.0:1812
?Trace : Sep 20 09:52:36 AuthServer: Entering process loop
Info : Sep 20 09:52:36 RadiusSocket: Listening on 0.0.0.0:1813
Info : Sep 20 09:52:36 StreamConnection: Connection thread started. Peer 127.0.0.1:12758
?Debug : Sep 20 09:52:36 StreamConnection: Connection using TCP socket
?Debug : Sep 20 09:52:36 StreamConnection: System message recived
?Debug : Sep 20 09:52:36 StreamConnection: Challenge response sent
?Debug : Sep 20 09:52:36 StreamConnection: System message recived
Info : Sep 20 09:52:36 StreamConnection: Connection successfully authorized, user id <-2>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: dialup features received
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: telephony features received
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Got license info..
?Debug : Sep 20 09:52:36 RADIUS DBA: Updating Named Pool: user_class
?Debug : Sep 20 09:52:36 RADIUS DBA: New Named Pool inserted: user_class
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 10/1/14/11. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 11/2/15/11. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 12/3/16/11. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 13/5/17/11. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 15/6/19/9. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 16/7/21/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 17/8/22/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 18/9/23/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 19/10/24/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 20/11/25/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 21/12/26/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 22/13/27/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 23/14/28/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 24/15/29/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 25/16/30/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 26/17/31/12. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 27/18/32/11. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 28/19/33/11. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 29/9/34/11. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 31/10/36/11. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 32/21/37/13. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP for IP-GroupID/A/Slink/Service: 33/22/38/13. 1 nodes
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP-traffic service <1> received
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Vendor <1234> attr <7> value size <26>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Vendor <1234> attr <7> value size <27>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP-traffic service <3> received
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP-traffic service <9> received
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP-traffic service <11> received
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Vendor <12341> attr <7> value size <26>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Vendor <12341> attr <7> value size <27>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP-traffic service <12> received
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Vendor <12341> attr <7> value size <26>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Vendor <12341> attr <7> value size <27>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: IP-traffic service <13> received
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
Info : Sep 20 09:52:36 RADIUS DBA: Inserting NAS. Data size <0>
Info : Sep 20 09:52:36 RADIUS DBA: Inserting NAS result. Data size <0>
Info : Sep 20 09:52:36 NASCache<127.0.0.1>: Created...
Info : Sep 20 09:52:36 RADIUS Stream[plugin]: NAS <127.0.0.1> added/modified
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: TimeRange <1>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: End receiving RADIUS attributes ...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: DialUp service <5>
Info : Sep 20 09:52:36 RADIUS DBA: Starting directions sort...
Info : Sep 20 09:52:36 RADIUS DBA: Finished directions sort...
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <1> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <2> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <3> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <5> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <6> with balance <350.671>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <7> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <8> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <9> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <10> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <11> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <12> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <13> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <14> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <15> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <16> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <17> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <18> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <19> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <20> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <21> with balance <0.000>
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Account <22> with balance <0.000>
Info : Sep 20 09:52:36 RADIUS Stream[plugin]: Updating realm list
?Debug : Sep 20 09:52:36 RADIUS DBA: Flushing REALM list
?Debug : Sep 20 09:52:36 RADIUS DBA: Info for login <ludmila> found. type <1>
?Debug : Sep 20 09:52:36 RADIUS DBA: info for user found. type <1> info addr <677432320>
?Debug : Sep 20 09:52:36 RADIUS DBA: search_user_info return info <677432320>
?Debug : Sep 20 09:52:36 RADIUS DBA: search_user_info return valid info
?Debug : Sep 20 09:52:36 RADIUS IPPool: Bind <a0a010c> : <a0a010c>
?Debug : Sep 20 09:52:36 RADIUS DBA: Setting interim interval <66> for session id <4960900-L-1>
?Debug : Sep 20 09:52:36 RADIUS DBA: id2core_add calling ...
?Debug : Sep 20 09:52:36 RADIUS DBA: id2core_add core_id <154> id <1>
?Debug : Sep 20 09:52:36 RADIUS Config: RADIUS server ready to serve requests
?Trace : Sep 20 09:52:36 RADIUS DBA: New state: ds_up
?Trace : Sep 20 09:52:36 AuthServer: Process loop step
?Debug : Sep 20 09:52:36 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 20 09:52:36 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 20 09:52:36 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 20 09:52:38 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 20 09:52:38 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 20 09:52:38 RADIUS Packet: Size <294>; HDR.Size <294>
?Debug : Sep 20 09:52:38 AcctServer: Recv...
?Debug : Sep 20 09:52:38 AcctServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 4; ID: 234
<Vendor: 0; Attr: 1>[7]: 6c75646d696c61
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000001
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a0a010c
<Vendor: 0; Attr: 9>[4]: ffffffff
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[12]: 3139322e3136382e302e3938
<Vendor: 0; Attr: 32>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 0; Attr: 40>[4]: 00000003
<Vendor: 0; Attr: 42>[4]: 00001bc4
<Vendor: 0; Attr: 43>[4]: 000002f4
<Vendor: 0; Attr: 44>[11]: 343936303930302d4c2d31
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 46>[4]: 00000424
<Vendor: 0; Attr: 47>[4]: 0000007e
<Vendor: 0; Attr: 48>[4]: 00000043
<Vendor: 0; Attr: 50>[11]: 343936303930312d422d31
<Vendor: 0; Attr: 51>[4]: 00000001
<Vendor: 0; Attr: 52>[4]: 00000000
<Vendor: 0; Attr: 53>[4]: 00000000
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[12]: 3139322e3136382e302e3938
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 91>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 12341; Attr: 12>[3]: 4c2d31
<Vendor: 12341; Attr: 13>[3]: 422d31
<Vendor: 12341; Attr: 14>[3]: 6e6730
<Vendor: 12341; Attr: 15>[4]: 00000006
?Debug : Sep 20 09:52:38 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:52:38 AcctServer: Acct packet with session ID: 4960900-L-1
?Debug : Sep 20 09:52:38 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:52:38 AcctServer: Acct-Interim-Update packet
?Debug : Sep 20 09:52:38 AcctServer: Acct-Start: User <ludmila>
?Debug : Sep 20 09:52:38 AcctServer: Updating session <4960900-L-1> input/output octets <7108>/<756> session time <1060>
?Debug : Sep 20 09:52:38 RADIUS DBA: Interim updating session <4960900-L-1> with timestamp <1284961958>
?Debug : Sep 20 09:52:38 RADIUS Stream[plugin]: edit log id <1>
?Debug : Sep 20 09:52:38 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 234
?Debug : Sep 20 09:52:38 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 20 09:52:38 RadiusSocket: RADIUS raw data sent
?Debug : Sep 20 09:52:38 AcctServer: Next...
?Debug : Sep 20 09:52:38 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 20 09:52:47 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 20 09:52:47 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 20 09:52:47 RADIUS Packet: Size <271>; HDR.Size <271>
?Debug : Sep 20 09:52:47 AuthServer: Recv...
?Debug : Sep 20 09:52:47 AuthServer: Packet from NAS <127.0.0.1>
?Debug : Sep 20 09:52:47 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:52:47 AuthServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 1; ID: 95
<Vendor: 0; Attr: 1>[5]: 7573657231
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000002
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[11]: 3139322e3136382e302e35
<Vendor: 0; Attr: 32>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 0; Attr: 44>[11]: 343936313936372d4c2d32
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[11]: 3139322e3136382e302e35
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 80>[16]: 7ad29c126e78eb206786508220007019
<Vendor: 0; Attr: 91>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 311; Attr: 11>[16]: bb1e68c4ccbac05f63b8a05d3a51adbd
<Vendor: 311; Attr: 25>[50]: 01008a569214943ab00f1f9427142ff17a7300000000000000006674e4bf0e3bdaa95a6c85299df49674fca578924722bb39
<Vendor: 12341; Attr: 12>[3]: 4c2d32
?Debug : Sep 20 09:52:47 AuthServer: User <user1> connecting
?Debug : Sep 20 09:52:47 AuthServer: Session for sessionid <user1> not found in <127.0.0.1> cache
?Debug : Sep 20 09:52:47 RADIUS DBA: Info for login <user1> found. type <1>
?Debug : Sep 20 09:52:47 AuthServer: Auth scheme: MS-CHAPv2
?Debug : Sep 20 09:52:47 AuthServer: MS-CHAPv2: Authorized user <user1>
?Debug : Sep 20 09:52:47 AuthServer: MS-CHAPv2: MPPE Keys send
?Debug : Sep 20 09:52:47 AuthServer: IP claimed: 0xa0a010d (<10.10.1.13>)
?Debug : Sep 20 09:52:47 AuthServer: Calling fill radius attributes for service. Attr storage size <2>
?Debug : Sep 20 09:52:47 AuthServer: fill_radius_data Vendor:<12341> Attr:<7> Val:<677697536> Size<26>
?Debug : Sep 20 09:52:47 AuthServer: fill_radius_data result <0> message <Unknown error: 0>
?Debug : Sep 20 09:52:47 AuthServer: fill_radius_data verifying packet. fetched val <in#1=all shape 128000 pass> size:<26>
?Debug : Sep 20 09:52:47 AuthServer: fill_radius_data Vendor:<12341> Attr:<7> Val:<677697568> Size<27>
?Debug : Sep 20 09:52:47 AuthServer: fill_radius_data result <0> message <Unknown error: 0>
?Debug : Sep 20 09:52:47 AuthServer: fill_radius_data verifying packet. fetched val <in#1=all shape 128000 pass> size:<26>
?Debug : Sep 20 09:52:47 AuthServer: Calling fill radius attributes for slink. Attr storage size <0>
?Debug : Sep 20 09:52:47 AuthServer: Calling fill radius attributes for NAS. Attr storage size <0>
Notice: Sep 20 09:52:47 AuthServer: Login OK <user1> from NAS <127.0.0.1> CLID <> Calling-station <192.168.0.5>
?Debug : Sep 20 09:52:47 AuthServer: Setting interim update interval from config
?Debug : Sep 20 09:52:47 AuthServer: Auth reply: RPacket:
Code: 2; ID: 95
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a0a010d
<Vendor: 0; Attr: 9>[4]: ffffffff
<Vendor: 0; Attr: 27>[4]: 00015180
<Vendor: 0; Attr: 85>[4]: 00000042
<Vendor: 311; Attr: 7>[4]: 00000001
<Vendor: 311; Attr: 8>[4]: 00000006
<Vendor: 311; Attr: 16>[34]: 8eb57561d5b6ac49dee9ffc503719165642c54dcb1847941d58bec344659476cfd5e
<Vendor: 311; Attr: 17>[34]: 8a1442253bec7dbdb61bf04f4e78705d7699c08c834722de03c458666b8280a97c51
<Vendor: 311; Attr: 26>[43]: 81533d32364243344345413338463037394442433938323142353641463245463743314641423939344333
<Vendor: 12341; Attr: 7>[26]: 696e23313d616c6c207368617065203132383030302070617373
<Vendor: 12341(0); Attr: 7>[27]: 6f757423313d616c6c207368617065203531323030302070617373
?Debug : Sep 20 09:52:47 RADIUS Packet: raw data constructed! size <284>
?Debug : Sep 20 09:52:47 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 20 09:52:47 RadiusSocket: RADIUS raw data sent
?Debug : Sep 20 09:52:47 AuthServer: Next...
?Trace : Sep 20 09:52:47 AuthServer: Process loop step
?Debug : Sep 20 09:52:47 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 20 09:52:47 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 20 09:52:47 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 20 09:52:47 RADIUS Packet: Size <248>; HDR.Size <248>
?Debug : Sep 20 09:52:47 AcctServer: Recv...
?Debug : Sep 20 09:52:47 AcctServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 4; ID: 222
<Vendor: 0; Attr: 1>[5]: 7573657231
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000002
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a0a010d
<Vendor: 0; Attr: 9>[4]: ffffffff
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[11]: 3139322e3136382e302e35
<Vendor: 0; Attr: 32>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 0; Attr: 40>[4]: 00000001
<Vendor: 0; Attr: 44>[11]: 343936313936372d4c2d32
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 50>[11]: 343936313936372d422d32
<Vendor: 0; Attr: 51>[4]: 00000001
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[11]: 3139322e3136382e302e35
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 91>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 12341; Attr: 12>[3]: 4c2d32
<Vendor: 12341; Attr: 13>[3]: 422d32
<Vendor: 12341; Attr: 14>[3]: 6e6731
<Vendor: 12341; Attr: 15>[4]: 00000007
?Debug : Sep 20 09:52:47 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:52:47 AcctServer: Acct packet with session ID: 4961967-L-2
?Debug : Sep 20 09:52:47 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:52:47 AcctServer: Acct-Start packet
?Debug : Sep 20 09:52:47 AcctServer: Acct-Start: User <user1>
?Debug : Sep 20 09:52:47 AcctServer: Acct-Session-Time (46) not present in accounting packet.
?Debug : Sep 20 09:52:47 AcctServer: No h323-setup-time (9, 25) attribute in accountig start packet. Setting to NOW <1284961967>!
?Debug : Sep 20 09:52:47 RADIUS DBA: Info for login <user1> found. type <1>
?Debug : Sep 20 09:52:47 RADIUS DBA: info for user found. type <1> info addr <677435392>
?Debug : Sep 20 09:52:47 RADIUS DBA: search_user_info return info <677435392>
?Debug : Sep 20 09:52:47 RADIUS DBA: search_user_info return valid info
?Debug : Sep 20 09:52:47 RADIUS IPPool: Bind <a0a010d> : <a0a010d>
?Debug : Sep 20 09:52:47 RADIUS DBA: Setting interim interval <66> for session id <4961967-L-2>
?Debug : Sep 20 09:52:47 RADIUS DBA: Calling send_session_log_init_sync ...
?Debug : Sep 20 09:52:47 RADIUS Stream[plugin]: send_session_log_init_sync
?Debug : Sep 20 09:52:47 RADIUS Stream[plugin]: init log id <2>
?Debug : Sep 20 09:52:47 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 222
?Debug : Sep 20 09:52:47 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 20 09:52:47 RadiusSocket: RADIUS raw data sent
?Debug : Sep 20 09:52:47 AcctServer: Next...
?Debug : Sep 20 09:52:47 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 20 09:53:05 RADIUS Stream[plugin]: Account <6> with balance <350.671>
?Debug : Sep 20 09:53:05 RADIUS Stream[plugin]: Account <6> with balance <350.671>
?Debug : Sep 20 09:53:06 RADIUS DBA: Correctly interim updated session <1> found. Leave untouched.
?Debug : Sep 20 09:53:06 RADIUS DBA: Null interim updated session <2> found. Setting last update for current datetime.
?Debug : Sep 20 09:53:06 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 20 09:53:37 RADIUS DBA: Correctly interim updated session <1> found. Leave untouched.
?Debug : Sep 20 09:53:37 RADIUS DBA: Correctly interim updated session <2> found. Leave untouched.
?Debug : Sep 20 09:53:37 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 20 09:53:44 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 20 09:53:44 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 20 09:53:44 RADIUS Packet: Size <294>; HDR.Size <294>
?Debug : Sep 20 09:53:44 AcctServer: Recv...
?Debug : Sep 20 09:53:44 AcctServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 4; ID: 114
<Vendor: 0; Attr: 1>[7]: 6c75646d696c61
<Vendor: 0; Attr: 4>[4]: 7f000001
<Vendor: 0; Attr: 5>[4]: 00000001
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a0a010c
<Vendor: 0; Attr: 9>[4]: ffffffff
<Vendor: 0; Attr: 30>[0]:
<Vendor: 0; Attr: 31>[12]: 3139322e3136382e302e3938
<Vendor: 0; Attr: 32>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 0; Attr: 40>[4]: 00000003
<Vendor: 0; Attr: 42>[4]: 00001be2
<Vendor: 0; Attr: 43>[4]: 00000318
<Vendor: 0; Attr: 44>[11]: 343936303930302d4c2d31
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 46>[4]: 00000466
<Vendor: 0; Attr: 47>[4]: 00000081
<Vendor: 0; Attr: 48>[4]: 00000046
<Vendor: 0; Attr: 50>[11]: 343936303930312d422d31
<Vendor: 0; Attr: 51>[4]: 00000001
<Vendor: 0; Attr: 52>[4]: 00000000
<Vendor: 0; Attr: 53>[4]: 00000000
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 0; Attr: 64>[4]: 00000001
<Vendor: 0; Attr: 65>[4]: 00000001
<Vendor: 0; Attr: 66>[12]: 3139322e3136382e302e3938
<Vendor: 0; Attr: 67>[12]: 3139322e3136382e302e3130
<Vendor: 0; Attr: 91>[16]: 737461742e6c6f63616c2e7369656974
<Vendor: 12341; Attr: 12>[3]: 4c2d31
<Vendor: 12341; Attr: 13>[3]: 422d31
<Vendor: 12341; Attr: 14>[3]: 6e6730
<Vendor: 12341; Attr: 15>[4]: 00000006
?Debug : Sep 20 09:53:53 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:53:53 AcctServer: Acct packet with session ID: 4961967-L-2
?Debug : Sep 20 09:53:53 RADIUS DBA: NAS found. Data size <0>
?Debug : Sep 20 09:53:53 AcctServer: Acct-Interim-Update packet
?Debug : Sep 20 09:53:53 AcctServer: Acct-Start: User <user1>
?Debug : Sep 20 09:53:53 AcctServer: Updating session <4961967-L-2> input/output octets <90061>/<2747300> session time <68>
?Debug : Sep 20 09:53:53 RADIUS DBA: Interim updating session <4961967-L-2> with timestamp <1284962033>
?Debug : Sep 20 09:53:53 RADIUS Stream[plugin]: edit log id <2>
?Debug : Sep 20 09:53:53 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 7
?Debug : Sep 20 09:53:53 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Sep 20 09:53:53 RadiusSocket: RADIUS raw data sent
?Debug : Sep 20 09:53:53 AcctServer: Next...
?Debug : Sep 20 09:53:53 RadiusSocket: Waiting for RADIUS raw data
?Debug : Sep 20 09:54:08 RADIUS DBA: Correctly interim updated session <1> found. Leave untouched.
?Debug : Sep 20 09:54:08 RADIUS DBA: Correctly interim updated session <2> found. Leave untouched.
?Debug : Sep 20 09:54:08 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 20 09:54:39 RADIUS DBA: Correctly interim updated session <1> found. Leave untouched.
?Debug : Sep 20 09:54:39 RADIUS DBA: Correctly interim updated session <2> found. Leave untouched.
?Debug : Sep 20 09:54:39 RADIUS Stream[plugin]: Ping reply received
?Debug : Sep 20 09:54:50 RadiusSocket: RADIUS packet successfully received
?Debug : Sep 20 09:54:50 RadiusSocket: RADIUS raw data obtained
?Debug : Sep 20 09:54:50 RADIUS Packet: Size <294>; HDR.Size <294>
?Debug : Sep 20 09:54:50 AcctServer: Recv...
?Debug : Sep 20 09:54:50 AcctServer: Packet from <127.0.0.1> packet dump: RPacket:
Code: 4; ID: 45
Созданный новый пользователь user1
