NAS Mikrotik + UTM5

fider83

Значит имеем NAS на Mikrotik. Авторизация в UTM осуществляется по средствам utm radius. При попытки установить сэссию (VPN) в логе radius_main.log
вот что пишется
?Debug : Feb 05 15:05:21 RADIUS Stream[plugin]: Ping reply received
?Debug : Feb 05 15:05:26 RADIUS Stream[plugin]: Ping reply received
?Debug : Feb 05 15:05:27 RadiusSocket: RADIUS packet successfully received
?Debug : Feb 05 15:05:27 RadiusSocket: RADIUS raw data obtained
?Debug : Feb 05 15:05:27 RADIUS Packet: Size <178>; HDR.Size <178>
?Debug : Feb 05 15:05:27 AuthServer: Recv...
?Debug : Feb 05 15:05:27 AuthServer: Packet from NAS <172.168.1.220>
?Debug : Feb 05 15:05:27 RADIUS DBA: NAS found. Data size <3>
?Debug : Feb 05 15:05:27 RADIUS DBA: NAS radius attr <14988> vendor <8> val <128k/128k>
?Debug : Feb 05 15:05:27 RADIUS DBA: NAS radius attr <14988> vendor <8> val <128k/128k>
?Debug : Feb 05 15:05:27 RADIUS DBA: NAS radius attr <14988> vendor <8> val <128k/128k>
?Debug : Feb 05 15:05:27 AuthServer: Packet from <172.168.1.220> packet dump: RPacket:
Code: 1; ID: 1
<Vendor: 0; Attr: 1>[4]: 74657374
<Vendor: 0; Attr: 4>[4]: aca801dc
<Vendor: 0; Attr: 5>[4]: 00000071
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 30>[13]: 3139322e3136382e352e323530
<Vendor: 0; Attr: 31>[13]: 3139322e3136382e352e323534
<Vendor: 0; Attr: 32>[8]: 4d696b726f54696b
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 311; Attr: 11>[16]: c304404cdf87ea83ce30e29113cffb1e
<Vendor: 311; Attr: 25>[50]: 0100cd1cd93a01cffd5de2d6d9723e5f487f00000000000000003ca57e9e212e9ec117ccff27aaa80d85e3710ae5dc3eec51

?Debug : Feb 05 15:05:27 AuthServer: User <test> connecting
?Debug : Feb 05 15:05:27 AuthServer: Session for sessionid <test> not found in <172.168.1.220> cache
?Debug : Feb 05 15:05:27 RADIUS DBA: Info for login <test> found. type <1>
?Debug : Feb 05 15:05:27 AuthServer: Auth scheme: MS-CHAPv2
?Debug : Feb 05 15:05:27 AuthServer: MS-CHAPv2: Authorized user <test>
?Debug : Feb 05 15:05:27 RADIUS IPPool: Dropped on timeout: 0x0a141402
?Debug : Feb 05 15:05:27 AuthServer: IP claimed: 0xa141402 (<10.20.20.2>)
?Debug : Feb 05 15:05:27 AuthServer: Allowed/recv CID: 10.20.20.2/192.168.5.254
Warn : Feb 05 15:05:27 AuthServer: Allowed CID mismatch! Rejecting ...
?Debug : Feb 05 15:05:27 AuthServer: Calling fill radius attributes for NAS. Attr storage size <3>
?Debug : Feb 05 15:05:27 AuthServer: fill_radius_data Vendor:<14988> Attr:<8> Val:<135488736> Size<9>
?Debug : Feb 05 15:05:27 AuthServer: fill_radius_data result <0> message <Success>
?Debug : Feb 05 15:05:27 AuthServer: fill_radius_data verifying packet. fetched val <128k/128k> size:<9>
?Debug : Feb 05 15:05:27 AuthServer: fill_radius_data Vendor:<14988> Attr:<8> Val:<135488784> Size<9>
?Debug : Feb 05 15:05:27 AuthServer: fill_radius_data result <0> message <Success>
?Debug : Feb 05 15:05:27 AuthServer: fill_radius_data verifying packet. fetched val <128k/128k> size:<9>
?Debug : Feb 05 15:05:27 AuthServer: fill_radius_data Vendor:<14988> Attr:<8> Val:<135402760> Size<9>
?Debug : Feb 05 15:05:27 AuthServer: fill_radius_data result <0> message <Success>
?Debug : Feb 05 15:05:27 AuthServer: fill_radius_data verifying packet. fetched val <128k/128k> size:<9>
Notice: Feb 05 15:05:27 AuthServer: Login incorrect <test> from NAS <172.168.1.220> CLID <192.168.5.250> Calling-station <192.168.5.254>
Notice: Feb 05 15:05:27 AuthServer: Authorization failed for user <test>
?Debug : Feb 05 15:05:27 AuthServer: Auth reply: RPacket:
Code: 3; ID: 1
<Vendor: 0; Attr: 18>[21]: 417574686f72697a6174696f6e206661696c65642e
<Vendor: 311; Attr: 26>[43]: 81533d35444432453646343334444546383535453045384231323135313942424235394236374339414334
<Vendor: 14988; Attr: 8>[9]: 3132386b2f3132386b
<Vendor: 14988(0); Attr: 8>[9]: 3132386b2f3132386b
<Vendor: 14988(1); Attr: 8>[9]: 3132386b2f3132386b

?Debug : Feb 05 15:05:27 RADIUS Packet: raw data constructed! size <145>
?Debug : Feb 05 15:05:27 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Feb 05 15:05:27 AuthServer: Next...
?Trace : Feb 05 15:05:27 AuthServer: Process loop step
?Debug : Feb 05 15:05:27 RadiusSocket: Waiting for RADIUS raw data
?Debug : Feb 05 15:05:27 RadiusSocket: RADIUS raw data sent
?Debug : Feb 05 15:05:31 RADIUS Stream[plugin]: Ping reply received

Во общем нужна помощь, заранее спасибо

starchik

покажи лог микротика при конекте, какую ошибку пишет?

вот тебе лог UTM'овского радиуса, когда клиент конектится

Код: Выделить всё

?Debug &#58; Feb 05 15&#58;56&#58;30 RadiusSocket&#58; RADIUS packet successfully received
?Debug &#58; Feb 05 15&#58;56&#58;30 RadiusSocket&#58; RADIUS raw data obtained
?Debug &#58; Feb 05 15&#58;56&#58;30 RADIUS Packet&#58; Size <176>; HDR.Size <176>
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Recv...
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Packet from NAS <192.168.8.1>
?Debug &#58; Feb 05 15&#58;56&#58;30 RADIUS DBA&#58; NAS found. Data size <0>
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Packet from <192.168.8.1> packet dump&#58; RPacket&#58;
Code&#58; 1; ID&#58; 3
<Vendor&#58; 0; Attr&#58; 1>&#91;5&#93;&#58; 64696d6f6e
<Vendor&#58; 0; Attr&#58; 4>&#91;4&#93;&#58; c0a80801
<Vendor&#58; 0; Attr&#58; 5>&#91;4&#93;&#58; 00000004
<Vendor&#58; 0; Attr&#58; 6>&#91;4&#93;&#58; 00000002
<Vendor&#58; 0; Attr&#58; 7>&#91;4&#93;&#58; 00000001
<Vendor&#58; 0; Attr&#58; 30>&#91;11&#93;&#58; 3139322e3136382e382e31
<Vendor&#58; 0; Attr&#58; 31>&#91;12&#93;&#58; 3139322e3136382e382e3232
<Vendor&#58; 0; Attr&#58; 32>&#91;8&#93;&#58; 4d696b726f54696b
<Vendor&#58; 0; Attr&#58; 61>&#91;4&#93;&#58; 00000005
<Vendor&#58; 311; Attr&#58; 11>&#91;16&#93;&#58; f5566fc85a408f4ceccdd4bfb9c86eb0
<Vendor&#58; 311; Attr&#58; 25>&#91;50&#93;&#58; 0100d5bdb80649a9bf0400a5cfee9515746a0000000000000000d3334c2ec9de3f853f3dcf2f86d8a6d3a5d0e1d73a58c15b
 
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; User <dimon> connecting
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Session for sessionid <dimon> not found in <192.168.8.1> cache
?Debug &#58; Feb 05 15&#58;56&#58;30 RADIUS DBA&#58; Info for login <dimon> found. type <1>
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Auth scheme&#58; MS-CHAPv2
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; MS-CHAPv2&#58; Authorized user <dimon> 
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; MS-CHAPv2&#58; MPPE Keys send
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; IP claimed&#58; 0xc0a88403 &#40;<192.168.132.3>&#41;
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Calling fill radius attributes for service. Attr storage size <1>
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; fill_radius_data Vendor&#58;<14988> Attr&#58;<8> Val&#58;<679067808> Size<18>
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; fill_radius_data result <0> message <Unknown error&#58; 0>
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; fill_radius_data verifying packet. fetched val <280k 280k 280k 5 1> size&#58;<18>
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Calling fill radius attributes for slink. Attr storage size <0>
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Calling fill radius attributes for NAS. Attr storage size <0>
 Notice&#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Login OK <dimon> from NAS <192.168.8.1> CLID <192.168.8.1> Calling-station <192.168.8.22>
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Setting interim update interval from config
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Auth reply&#58; RPacket&#58;
Code&#58; 2; ID&#58; 3
<Vendor&#58; 0; Attr&#58; 6>&#91;4&#93;&#58; 00000002
<Vendor&#58; 0; Attr&#58; 7>&#91;4&#93;&#58; 00000001
<Vendor&#58; 0; Attr&#58; 8>&#91;4&#93;&#58; c0a88403
<Vendor&#58; 0; Attr&#58; 9>&#91;4&#93;&#58; ffffffff
<Vendor&#58; 0; Attr&#58; 27>&#91;4&#93;&#58; 00015180
<Vendor&#58; 0; Attr&#58; 85>&#91;4&#93;&#58; 0000005a
<Vendor&#58; 311; Attr&#58; 7>&#91;4&#93;&#58; 00000001
<Vendor&#58; 311; Attr&#58; 8>&#91;4&#93;&#58; 00000006
<Vendor&#58; 311; Attr&#58; 16>&#91;34&#93;&#58; 85e83c52eee74e4227e8a3037cdc3056ef57256100e830e009a3991ee58deb597f80
<Vendor&#58; 311; Attr&#58; 17>&#91;34&#93;&#58; 8e9ba1103635bcb4b867cfef28d2100ec780089d3d0dbdb27497b4ab5ed4e0e634c6
<Vendor&#58; 311; Attr&#58; 26>&#91;43&#93;&#58; 81533d30343836423543384544333246314235323733344639303741464637413241364541424332443244
<Vendor&#58; 14988; Attr&#58; 8>&#91;18&#93;&#58; 3238306b203238306b203238306b20352031

?Debug &#58; Feb 05 15&#58;56&#58;30 RADIUS Packet&#58; raw data constructed! size <241>
?Debug &#58; Feb 05 15&#58;56&#58;30 RadiusSocket&#58; Moving RADIUS packet into send queue
?Debug &#58; Feb 05 15&#58;56&#58;30 RadiusSocket&#58; RADIUS raw data sent
?Debug &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Next...
?Trace &#58; Feb 05 15&#58;56&#58;30 AuthServer&#58; Process loop step
?Debug &#58; Feb 05 15&#58;56&#58;30 RadiusSocket&#58; Waiting for RADIUS raw data
?Debug &#58; Feb 05 15&#58;56&#58;30 RadiusSocket&#58; RADIUS packet successfully received
?Debug &#58; Feb 05 15&#58;56&#58;30 RadiusSocket&#58; RADIUS packet successfully received

fider83

Ситуевина еще стала интересней, вроде начинает подключаться, проверка логина и пароля проходит, сворачивается в трей и рветься

вот собственно сам лог

?Debug : Feb 05 21:25:05 RADIUS Stream[plugin]: Ping reply received
?Debug : Feb 05 21:25:10 RADIUS Stream[plugin]: Ping reply received
?Debug : Feb 05 21:25:15 RADIUS Stream[plugin]: Ping reply received
?Debug : Feb 05 21:25:16 RadiusSocket: RADIUS packet successfully received
?Debug : Feb 05 21:25:16 RadiusSocket: RADIUS raw data obtained
?Debug : Feb 05 21:25:16 RADIUS Packet: Size <176>; HDR.Size <176>
?Debug : Feb 05 21:25:16 AuthServer: Recv...
?Debug : Feb 05 21:25:16 AuthServer: Packet from NAS <172.168.1.220>
?Debug : Feb 05 21:25:16 RADIUS DBA: NAS found. Data size <0>
?Debug : Feb 05 21:25:16 AuthServer: Packet from <172.168.1.220> packet dump: RPacket:
Code: 1; ID: 35
<Vendor: 0; Attr: 1>[4]: 74657374
<Vendor: 0; Attr: 4>[4]: aca801dc
<Vendor: 0; Attr: 5>[4]: 00000083
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 30>[13]: 3137322e3136382e312e323230
<Vendor: 0; Attr: 31>[11]: 3137322e3136382e312e31
<Vendor: 0; Attr: 32>[8]: 4d696b726f54696b
<Vendor: 0; Attr: 61>[4]: 00000005
<Vendor: 311; Attr: 11>[16]: 7a7ffa9ae8bfb6f707430414271dc0ef
<Vendor: 311; Attr: 25>[50]: 0100633f4a24249bbeaeb2336a6ce175e51f0000000000000000cd37ef06b3a1bffa7d99370e2f5a61e0b06b90402aee5de4

?Debug : Feb 05 21:25:16 AuthServer: User <test> connecting
?Debug : Feb 05 21:25:16 AuthServer: Session for sessionid <test> not found in <172.168.1.220> cache
?Debug : Feb 05 21:25:16 RADIUS DBA: Info for login <test> found. type <1>
?Debug : Feb 05 21:25:16 AuthServer: Auth scheme: MS-CHAPv2
?Debug : Feb 05 21:25:16 AuthServer: MS-CHAPv2: Authorized user <test>
?Debug : Feb 05 21:25:16 AuthServer: IP claimed: 0xa141402 (<10.20.20.2>)
?Debug : Feb 05 21:25:16 AuthServer: Calling fill radius attributes for service. Attr storage size <0>
?Debug : Feb 05 21:25:16 AuthServer: Calling fill radius attributes for slink. Attr storage size <0>
?Debug : Feb 05 21:25:16 AuthServer: Calling fill radius attributes for NAS. Attr storage size <0>
Notice: Feb 05 21:25:16 AuthServer: Login OK <test> from NAS <172.168.1.220> CLID <172.168.1.220> Calling-station <172.168.1.1>
?Debug : Feb 05 21:25:16 AuthServer: Setting interim update interval from config
?Debug : Feb 05 21:25:16 AuthServer: Auth reply: RPacket:
Code: 2; ID: 35
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a141402
<Vendor: 0; Attr: 9>[4]: ffffffff
<Vendor: 0; Attr: 10>[4]: 00000000
<Vendor: 0; Attr: 27>[4]: 00015180
<Vendor: 311; Attr: 26>[43]: 81533d32353637343246463838453538464343433934464636314546353339363144394346323434343737

?Debug : Feb 05 21:25:16 RADIUS Packet: raw data constructed! size <107>
?Debug : Feb 05 21:25:16 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Feb 05 21:25:16 AuthServer: Next...
?Trace : Feb 05 21:25:16 AuthServer: Process loop step
?Debug : Feb 05 21:25:16 RadiusSocket: Waiting for RADIUS raw data
?Debug : Feb 05 21:25:16 RadiusSocket: RADIUS raw data sent
?Debug : Feb 05 21:25:16 RadiusSocket: RADIUS packet successfully received
?Debug : Feb 05 21:25:16 RadiusSocket: RADIUS raw data obtained
?Debug : Feb 05 21:25:16 RADIUS Packet: Size <128>; HDR.Size <128>
?Debug : Feb 05 21:25:16 AcctServer: Recv...
?Debug : Feb 05 21:25:16 AcctServer: Packet from <172.168.1.220> packet dump: RPacket:
Code: 4; ID: 36
<Vendor: 0; Attr: 1>[4]: 74657374
<Vendor: 0; Attr: 4>[4]: aca801dc
<Vendor: 0; Attr: 5>[4]: 00000083
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a141402
<Vendor: 0; Attr: 30>[13]: 3137322e3136382e312e323230
<Vendor: 0; Attr: 31>[11]: 3137322e3136382e312e31
<Vendor: 0; Attr: 32>[8]: 4d696b726f54696b
<Vendor: 0; Attr: 40>[4]: 00000001
<Vendor: 0; Attr: 41>[4]: 00000000
<Vendor: 0; Attr: 44>[8]: 3831393030303030
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 61>[4]: 00000005

?Debug : Feb 05 21:25:16 RADIUS DBA: NAS found. Data size <0>
?Debug : Feb 05 21:25:16 AcctServer: Acct packet with session ID: 81900000
?Debug : Feb 05 21:25:16 RADIUS DBA: NAS found. Data size <0>
?Debug : Feb 05 21:25:16 AcctServer: Acct-Start packet
?Debug : Feb 05 21:25:16 AcctServer: Acct-Start: User <test>
?Debug : Feb 05 21:25:16 AcctServer: Acct-Session-Time (46) not present in accounting packet.
?Debug : Feb 05 21:25:16 AcctServer: No h323-setup-time (9, 25) attribute in accountig start packet. Setting to NOW <1233858316>!
?Debug : Feb 05 21:25:16 RADIUS DBA: Info for login <test> found. type <1>
?Debug : Feb 05 21:25:16 RADIUS DBA: info for user found. type <1> info addr <167793088>
?Debug : Feb 05 21:25:16 RADIUS DBA: search_user_info return info <167793088>
?Debug : Feb 05 21:25:16 RADIUS DBA: search_user_info return valid info
?Debug : Feb 05 21:25:16 RADIUS IPPool: Bind <a141402> : <a141402>
?Debug : Feb 05 21:25:16 RADIUS DBA: Setting interim interval <0> for session id <81900000>
?Debug : Feb 05 21:25:16 RADIUS DBA: Calling send_session_log_init_sync ...
?Debug : Feb 05 21:25:16 RADIUS Stream[plugin]: send_session_log_init_sync
?Debug : Feb 05 21:25:16 RADIUS Stream[plugin]: init log id <2>
?Debug : Feb 05 21:25:16 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 36

?Debug : Feb 05 21:25:16 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Feb 05 21:25:16 AcctServer: Next...
?Debug : Feb 05 21:25:16 RadiusSocket: Waiting for RADIUS raw data
?Debug : Feb 05 21:25:16 RadiusSocket: RADIUS packet successfully received
?Debug : Feb 05 21:25:16 RadiusSocket: RADIUS raw data sent
?Debug : Feb 05 21:25:16 RadiusSocket: RADIUS raw data obtained
?Debug : Feb 05 21:25:16 RADIUS Packet: Size <176>; HDR.Size <176>
?Debug : Feb 05 21:25:16 AcctServer: Recv...
?Debug : Feb 05 21:25:16 AcctServer: Packet from <172.168.1.220> packet dump: RPacket:
Code: 4; ID: 37
<Vendor: 0; Attr: 1>[4]: 74657374
<Vendor: 0; Attr: 4>[4]: aca801dc
<Vendor: 0; Attr: 5>[4]: 00000083
<Vendor: 0; Attr: 6>[4]: 00000002
<Vendor: 0; Attr: 7>[4]: 00000001
<Vendor: 0; Attr: 8>[4]: 0a141402
<Vendor: 0; Attr: 30>[13]: 3137322e3136382e312e323230
<Vendor: 0; Attr: 31>[11]: 3137322e3136382e312e31
<Vendor: 0; Attr: 32>[8]: 4d696b726f54696b
<Vendor: 0; Attr: 40>[4]: 00000002
<Vendor: 0; Attr: 41>[4]: 00000000
<Vendor: 0; Attr: 42>[4]: 0000007a
<Vendor: 0; Attr: 43>[4]: 0000005c
<Vendor: 0; Attr: 44>[8]: 3831393030303030
<Vendor: 0; Attr: 45>[4]: 00000001
<Vendor: 0; Attr: 46>[4]: 00000000
<Vendor: 0; Attr: 47>[4]: 00000008
<Vendor: 0; Attr: 48>[4]: 00000008
<Vendor: 0; Attr: 49>[4]: 00000009
<Vendor: 0; Attr: 52>[4]: 00000000
<Vendor: 0; Attr: 53>[4]: 00000000
<Vendor: 0; Attr: 61>[4]: 00000005

?Debug : Feb 05 21:25:16 RADIUS DBA: NAS found. Data size <0>
?Debug : Feb 05 21:25:16 AcctServer: Acct packet with session ID: 81900000
?Debug : Feb 05 21:25:16 RADIUS DBA: NAS found. Data size <0>
?Debug : Feb 05 21:25:16 AcctServer: Acct-Stop packet
?Debug : Feb 05 21:25:16 RADIUS DBA: Session erase ... login type <1>
?Debug : Feb 05 21:25:16 RADIUS DBA: login type login_pool or login_named_pool
?Debug : Feb 05 21:25:16 RADIUS IPPool: Released <a141402>
?Debug : Feb 05 21:25:16 RADIUS Stream[plugin]: finish log id <2>
?Debug : Feb 05 21:25:16 AcctServer: Reply packet dump: RPacket:
Code: 5; ID: 37

?Debug : Feb 05 21:25:16 RadiusSocket: Moving RADIUS packet into send queue
?Debug : Feb 05 21:25:16 AcctServer: Next...
?Debug : Feb 05 21:25:16 RadiusSocket: Waiting for RADIUS raw data
?Debug : Feb 05 21:25:16 RadiusSocket: RADIUS raw data sent
?Debug : Feb 05 21:25:20 RADIUS Stream[plugin]: Ping reply received

fider83

Ответ на данную проблему http://forum.mikrotik.com/viewtopic.php?f=10&t=9293

starchik

странно, когда в профилях я не указывал IP у меня вобще не конектилось....

MiO · Сообщение **MiO** » Пт фев 06, 2009 17:53

настройки микротика покажи