Ошибка 691
Добавлено: Чт фев 25, 2010 2:21 pm
На форуме встречал подобный проблемы, но для себя решения не нашел. Тестовая система работает на разных серверах: на одном ВПН сервер, на другом Абиллс
Лог подключения к впн серверу
Лог подключения к радиус-серверу:
Лог абилса:
Что-то я не пойму, пользователь не проходит авторизацию на впн-сервере или получает ответ от радиус сервера? Тут я слегка запутался :-\
Лог подключения к впн серверу
Код: Выделить всё
Feb 25 16:47:05 r13 pptpd[10705]: MGR: Launching /usr/sbin/pptpctrl to handle client
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: local address = 10.13.0.1
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: remote address = 192.168.1.1
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: pppd options file = /etc/ppp/pptpd-options
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Client 10.13.101.1 control connection started
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Received PPTP Control Message (type: 1)
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Made a START CTRL CONN RPLY packet
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: I wrote 156 bytes to the client.
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Sent packet to client
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Received PPTP Control Message (type: 7)
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Set parameters to 100000000 maxbps, 64 window size
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Made a OUT CALL RPLY packet
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Starting call (launching pppd, opening GRE)
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: pty_fd = 6
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: tty_fd = 7
Feb 25 16:47:05 r13 pptpd[10706]: CTRL (PPPD Launcher): program binary = /usr/sbin/pppd
Feb 25 16:47:05 r13 pptpd[10706]: CTRL (PPPD Launcher): local address = 10.13.0.1
Feb 25 16:47:05 r13 pptpd[10706]: CTRL (PPPD Launcher): remote address = 192.168.1.1
Feb 25 16:47:05 r13 pppd[10706]: Plugin radius.so loaded.
Feb 25 16:47:05 r13 pppd[10706]: RADIUS plugin initialized.
Feb 25 16:47:05 r13 pppd[10706]: Plugin radattr.so loaded.
Feb 25 16:47:05 r13 pppd[10706]: RADATTR plugin initialized.
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: I wrote 32 bytes to the client.
Feb 25 16:47:05 r13 pppd[10706]: Plugin /usr/lib/pptpd/pptpd-logwtmp.so loaded.
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Sent packet to client
Feb 25 16:47:05 r13 pppd[10706]: pptpd-logwtmp: $Version$
Feb 25 16:47:05 r13 pppd[10706]: pppd 2.4.5 started by root, uid 0
Feb 25 16:47:05 r13 pppd[10706]: using channel 1905
Feb 25 16:47:05 r13 pppd[10706]: Using interface ppp0
Feb 25 16:47:05 r13 pppd[10706]: Connect: ppp0 <--> /dev/pts/1
Feb 25 16:47:05 r13 pppd[10706]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MS-v2> <magic 0x1fadbde5> <pcomp> <accomp>]
Feb 25 16:47:05 r13 pptpd[10705]: GRE: Bad checksum from pppd.
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Received PPTP Control Message (type: 15)
Feb 25 16:47:05 r13 pptpd[10705]: CTRL: Got a SET LINK INFO packet with standard ACCMs
Feb 25 16:47:05 r13 pptpd[10705]: GRE: accepting packet #0
Feb 25 16:47:05 r13 pppd[10706]: rcvd [LCP ConfReq id=0x0 <mru 1400> <magic 0x12917640> <pcomp> <accomp> <callback CBCP>]
Feb 25 16:47:05 r13 pppd[10706]: sent [LCP ConfRej id=0x0 <callback CBCP>]
Feb 25 16:47:05 r13 pptpd[10705]: GRE: accepting packet #1
Feb 25 16:47:05 r13 pppd[10706]: rcvd [LCP ConfReq id=0x1 <mru 1400> <magic 0x12917640> <pcomp> <accomp>]
Feb 25 16:47:05 r13 pppd[10706]: sent [LCP ConfAck id=0x1 <mru 1400> <magic 0x12917640> <pcomp> <accomp>]
Feb 25 16:47:08 r13 pppd[10706]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <auth chap MS-v2> <magic 0x1fadbde5> <pcomp> <accomp>]
Feb 25 16:47:08 r13 pptpd[10705]: GRE: accepting packet #2
Feb 25 16:47:08 r13 pptpd[10705]: CTRL: Received PPTP Control Message (type: 15)
Feb 25 16:47:08 r13 pptpd[10705]: CTRL: Ignored a SET LINK INFO packet with real ACCMs!
Feb 25 16:47:08 r13 pptpd[10705]: GRE: accepting packet #3
Feb 25 16:47:08 r13 pptpd[10705]: GRE: accepting packet #4
Feb 25 16:47:08 r13 pppd[10706]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <auth chap MS-v2> <magic 0x1fadbde5> <pcomp> <accomp>]
Feb 25 16:47:08 r13 pppd[10706]: sent [CHAP Challenge id=0x83 <5eaac54a8e423784718f1cb85f49fdaa>, name = "pptpd"]
Feb 25 16:47:08 r13 pppd[10706]: rcvd [LCP Ident id=0x2 magic=0x12917640 "MSRASV5.10"]
Feb 25 16:47:08 r13 pppd[10706]: rcvd [LCP Ident id=0x3 magic=0x12917640 "MSRAS-0-TEST"]
Feb 25 16:47:08 r13 pptpd[10705]: GRE: accepting packet #5
Feb 25 16:47:08 r13 pppd[10706]: rcvd [CHAP Response id=0x83 <773d7324ea08cc320996bdd80455b92a00000000000000000869ea620a01741295ce79b8e70b8e2a651c06635d3bb65d00>, name = "testos"]
Feb 25 16:47:08 r13 pppd[10706]: rc_avpair_new: unknown attribute 11
Feb 25 16:47:08 r13 pppd[10706]: rc_avpair_new: unknown attribute 25
Feb 25 16:47:08 r13 pppd[10706]: RADATTR plugin wrote 0 line(s) to file /var/run/radattr.ppp0.
Feb 25 16:47:08 r13 pppd[10706]:
Feb 25 16:47:08 r13 pppd[10706]: Peer testos failed CHAP authentication
Feb 25 16:47:08 r13 pppd[10706]: sent [CHAP Failure id=0x83 ""]
Feb 25 16:47:08 r13 pppd[10706]: sent [LCP TermReq id=0x2 "Authentication failed"]
Feb 25 16:47:08 r13 pptpd[10705]: CTRL: Received PPTP Control Message (type: 15)
Feb 25 16:47:08 r13 pptpd[10705]: CTRL: Got a SET LINK INFO packet with standard ACCMs
Feb 25 16:47:08 r13 pptpd[10705]: GRE: accepting packet #6
Feb 25 16:47:08 r13 pppd[10706]: rcvd [LCP TermAck id=0x2 "Authentication failed"]
Feb 25 16:47:08 r13 pppd[10706]: Connection terminated.
Feb 25 16:47:08 r13 pptpd[10705]: CTRL: Received PPTP Control Message (type: 12)
Feb 25 16:47:08 r13 pptpd[10705]: CTRL: Made a CALL DISCONNECT RPLY packet
Feb 25 16:47:08 r13 pptpd[10705]: CTRL: Received CALL CLR request (closing call)
Feb 25 16:47:08 r13 pptpd[10705]: CTRL: Reaping child PPP[10706]
Feb 25 16:47:09 r13 pppd[10706]: RADATTR plugin removed file /var/run/radattr.ppp0.
Feb 25 16:47:09 r13 pppd[10706]: Exit.
Feb 25 16:47:09 r13 pptpd[10705]: CTRL: Client 10.13.101.1 control connection finished
Feb 25 16:47:09 r13 pptpd[10705]: CTRL: Exiting now
Feb 25 16:47:09 r13 pptpd[10478]: MGR: Reaped child 10705
Лог подключения к радиус-серверу:
Код: Выделить всё
rad_recv: Access-Request packet from host 172.29.32.14 port 52354, id=53, length=52
Service-Type = Framed-User
Framed-Protocol = PPP
User-Name = "testos"
NAS-IP-Address = 172.29.32.106
NAS-Port = 0
+- entering group authorize {...}
++[preprocess] returns ok
Exec-Program output: Auth-Type := Accept
Exec-Program-Wait: value-pairs: Auth-Type := Accept
Exec-Program: returned: 0
++[abills_preauth] returns ok
++[mschap] returns noop
[files] users: Matched entry DEFAULT at line 1
++[files] returns ok
Exec-Program output: Acct-Interim-Interval = 60, Session-Timeout = 284587, PPPD-Upstream-Speed-Limit = 1000, Octets-Direction = 0, Framed-IP-Address = 10.13.101.1, Session-Octets-Limit = 2147483648, Framed-IP-Netmask = 255.255.255.255, PPPD-Downstream-Speed-Limit = 1000,
Exec-Program-Wait: plaintext: Acct-Interim-Interval = 60, Session-Timeout = 284587, PPPD-Upstream-Speed-Limit = 1000, Octets-Direction = 0, Framed-IP-Address = 10.13.101.1, Session-Octets-Limit = 2147483648, Framed-IP-Netmask = 255.255.255.255, PPPD-Downstream-Speed-Limit = 1000,
Exec-Program: returned: 0
++[abills_auth] returns ok
Found Auth-Type = Accept
Auth-Type = Accept, accepting the user
Sending Access-Accept of id 53 to 172.29.32.14 port 52354
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 0 ID 53 with timestamp +7
Ready to process requests.
Лог абилса:
Код: Выделить всё
2010-02-25 16:56:53 LOG_INFO: AUTH [testos] NAS: 1 (172.29.32.106) GT: 0.03483