<span style="font-family: -webkit-monospace; font-size: 16px;
-webkit-border-horizontal-spacing: 2px; -webkit-border-vertical-spacing: 2px;
">Everything looks fine in IP addresses, but the problem is still the
same. <br />Here again the log of Mikrotik and freeradius:</span><br />
<br />
Mikrotik debug log<br />
<br />
<br />
01:33:40 pppoe,info PPPoE connection established from 00:15:AF:1F:23:1A <br
/>
01:33:40 pppoe,ppp,info <pppoe-0>: waiting for call... <br />
01:33:40 radius,debug new request 53:02 code=Access-Request service=ppp
called-id=pppoe-in <br />
01:33:40 radius,debug sending 53:02 to 192.168.200.2:1812 <br />
01:33:40 radius,debug,packet sending Access-Request with id 8 to
192.168.200.2:1812 <br />
01:33:40 radius,debug,packet Signature =
0x83d0415d6b98f0421df6bb83a01bdb28 <br />
01:33:40 radius,debug,packet Service-Type = 2 <br />
01:33:40 radius,debug,packet Framed-Protocol = 1 <br />
01:33:40 radius,debug,packet NAS-Port = 10 <br />
01:33:40 radius,debug,packet NAS-Port-Type = 15 <br />
01:33:40 radius,debug,packet User-Name = "lacho" <br />
01:33:40 radius,debug,packet Calling-Station-Id =
"00:15:AF:1F:23:1A" <br />
01:33:40 radius,debug,packet Called-Station-Id =
"pppoe-in" <br />
01:33:40 radius,debug,packet NAS-Port-Id = "ether1" <br />
01:33:40 radius,debug,packet CHAP-Challenge =
0xe3c819400560adadbf019f209dc42f7e <br />
01:33:40 radius,debug,packet CHAP-Password =
0x01dad26d1d56167a1899b3e9c8a8ba01 <br />
01:33:40 radius,debug,packet 18 <br />
01:33:40 radius,debug,packet NAS-Identifier =
"TEST-RADIUS" <br />
01:33:40 radius,debug,packet NAS-IP-Address =
192.168.200.4 <br />
01:33:41 radius,debug resending 53:02 <br />
01:33:41 radius,debug,packet sending Access-Request with id 8 to
192.168.200.2:1812 <br />
01:33:41 radius,debug,packet Signature =
0x83d0415d6b98f0421df6bb83a01bdb28 <br />
01:33:41 radius,debug,packet Service-Type = 2 <br />
01:33:41 radius,debug,packet Framed-Protocol = 1 <br />
01:33:41 radius,debug,packet NAS-Port = 10 <br />
01:33:41 radius,debug,packet NAS-Port-Type = 15 <br />
01:33:41 radius,debug,packet User-Name = "lacho" <br />
01:33:41 radius,debug,packet Calling-Station-Id =
"00:15:AF:1F:23:1A" <br />
01:33:41 radius,debug,packet Called-Station-Id =
"pppoe-in" <br />
01:33:41 radius,debug,packet NAS-Port-Id = "ether1" <br />
01:33:41 radius,debug,packet CHAP-Challenge =
0xe3c819400560adadbf019f209dc42f7e <br />
01:33:41 radius,debug,packet CHAP-Password =
0x01dad26d1d56167a1899b3e9c8a8ba01 <br />
01:33:41 radius,debug,packet 18 <br />
01:33:41 radius,debug,packet NAS-Identifier =
"TEST-RADIUS" <br />
01:33:41 radius,debug,packet NAS-IP-Address =
192.168.200.4 <br />
01:33:41 radius,debug resending 53:02 <br />
01:33:41 radius,debug,packet sending Access-Request with id 8 to
192.168.200.2:1812 <br />
01:33:41 radius,debug,packet Signature =
0x83d0415d6b98f0421df6bb83a01bdb28 <br />
01:33:41 radius,debug,packet Service-Type = 2 <br />
01:33:41 radius,debug,packet Framed-Protocol = 1 <br />
01:33:41 radius,debug,packet NAS-Port = 10 <br />
01:33:41 radius,debug,packet NAS-Port-Type = 15 <br />
01:33:41 radius,debug,packet User-Name = "lacho" <br />
01:33:41 radius,debug,packet Calling-Station-Id =
"00:15:AF:1F:23:1A" <br />
<div>
<div>01:33:41 radius,debug,packet Called-Station-Id =
"pppoe-in" </div>
<div>01:33:41 radius,debug,packet NAS-Port-Id =
"ether1" </div>
<div>01:33:41 radius,debug,packet CHAP-Challenge =
0xe3c819400560adadbf019f209dc42f7e </div>
<div>01:33:41 radius,debug,packet CHAP-Password =
0x01dad26d1d56167a1899b3e9c8a8ba01 </div>
<div>01:33:41 radius,debug,packet 18 </div>
<div>01:33:41 radius,debug,packet NAS-Identifier =
"TEST-RADIUS" </div>
<div>01:33:41 radius,debug,packet NAS-IP-Address =
192.168.200.4 </div>
<div>01:33:41 radius,debug timeout for 53:02 </div>
<div>01:33:41 pppoe,ppp,info <pppoe-lacho>: terminating... - user lacho
authentication failed - radius timeout (6) </div>
<div>01:33:41 pppoe,ppp,info <pppoe-lacho>: disconnected </div>
</div>
<div><br /></div>
<div><br /></div>
<div><br /></div>
<div><br /></div>
<div><br /></div>
<div>Freeradius debug log:</div>
<div><br /></div>
<div>
<div>Sending Access-Accept of id 7 to 192.168.200.4 port 32768</div>
<div> Acct-Interim-Interval = 300</div>
<div> Session-Timeout = 31</div>
<div> Mikrotik-Xmit-Limit = 1073217536</div>
<div> Framed-IP-Address = 10.8.15.44</div>
<div> Mikrotik-Recv-Limit = 1073217536</div>
<div> Framed-IP-Netmask = 255.255.255.255</div>
<div>Thu Mar 19 12:37:16 2009 : Debug: Finished request 3</div>
<div>Thu Mar 19 12:37:16 2009 : Debug: Going to the next request</div>
<div>Thu Mar 19 12:37:16 2009 : Debug: Thread 4 waiting to be assigned a
request</div>
<div>rad_recv: Access-Request packet from host 192.168.200.4:32768, id=8,
length=144</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: --- Walking the entire request list
---</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Cleaning up request 3 ID 7 with timestamp
49c2205c</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Waking up in 31 seconds...</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Threads: total/active/spare threads =
5/0/5</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Thread 5 got semaphore</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Thread 5 handling request 4, (1 handled
so far)</div>
<div> Service-Type = Framed-User</div>
<div> Framed-Protocol = PPP</div>
<div> NAS-Port = 10</div>
<div> NAS-Port-Type = Ethernet</div>
<div> User-Name = "lacho"</div>
<div> Calling-Station-Id =
"00:15:AF:1F:23:1A"</div>
<div> Called-Station-Id = "pppoe-in"</div>
<div> NAS-Port-Id = "ether1"</div>
<div> CHAP-Challenge =
0xe3c819400560adadbf019f209dc42f7e</div>
<div> CHAP-Password =
0x01dad26d1d56167a1899b3e9c8a8ba0118</div>
<div> NAS-Identifier = "TEST-RADIUS"</div>
<div> NAS-IP-Address = 192.168.200.4</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Processing the authorize section
of radiusd.conf</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: modcall: entering group authorize for
request 4</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 4</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 4</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: modcall[authorize]: module
"preprocess" returns ok for request 4</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: modsingle[authorize]: calling
pre_auth (rlm_exec) for request 4</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Exec-Program output: Auth-Type :=
Accept</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Exec-Program-Wait: value-pairs: Auth-Type
:= Accept</div>
<div>rad_recv: Access-Request packet from host 192.168.200.4:32768, id=8,
length=144</div>
<div>Thu Mar 19 12:37:31 2009 : Error: Discarding duplicate request from client
TEST-RADIUS:32768 - ID: 8 due to unfinished request 4</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: rl_next: returning NULL</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Waking up in 31 seconds...</div>
<div>Thu Mar 19 12:37:31 2009 : Debug: Threads: total/active/spare threads =
5/1/4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: Exec-Program: returned: 0</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: modsingle[authorize]: returned
from pre_auth (rlm_exec) for request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: modcall[authorize]: module
"pre_auth" returns ok for request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: modsingle[authorize]: calling
mschap (rlm_mschap) for request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: modsingle[authorize]: returned
from mschap (rlm_mschap) for request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: modcall[authorize]: module
"mschap" returns noop for request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: users: Matched entry
DEFAULT at line 52</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: modcall[authorize]: module "files"
returns ok for request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: modcall: leaving group authorize (returns
ok) for request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: rad_check_password: Found
Auth-Type Accept</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: rad_check_password: Auth-Type =
Accept, accepting the user</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: Exec-Program output:
Acct-Interim-Interval = 300, Session-Timeout = 31, Mikrotik-Xmit-Limit =
1073217536, Framed-IP-Address = 10.8.15.38, Mikrotik-Recv-Limit = 1073217536,
Framed-IP-Netmask = 255.255.255.255,</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: Exec-Program-Wait: value-pairs:
Acct-Interim-Interval = 300, Session-Timeout = 31, Mikrotik-Xmit-Limit =
1073217536, Framed-IP-Address = 10.8.15.38, Mikrotik-Recv-Limit = 1073217536,
Framed-IP-Netmask = 255.255.255.255,</div>
<div>rad_recv: Access-Request packet from host 192.168.200.4:32768, id=8,
length=144</div>
<div>Thu Mar 19 12:37:32 2009 : Error: Discarding duplicate request from client
TEST-RADIUS:32768 - ID: 8 due to unfinished request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: --- Walking the entire request list
---</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: Waking up in 5 seconds...</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: Exec-Program: returned: 0</div>
<div>Sending Access-Accept of id 8 to 192.168.200.4 port 32768</div>
<div> Acct-Interim-Interval = 300</div>
<div> Session-Timeout = 31</div>
<div> Mikrotik-Xmit-Limit = 1073217536</div>
<div> Framed-IP-Address = 10.8.15.38</div>
<div> Mikrotik-Recv-Limit = 1073217536</div>
<div> Framed-IP-Netmask = 255.255.255.255</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: Finished request 4</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: Going to the next request</div>
<div>Thu Mar 19 12:37:32 2009 : Debug: Thread 5 waiting to be assigned a
request</div>
<div>Thu Mar 19 12:37:37 2009 : Debug: --- Walking the entire request list
---</div>
<div>Thu Mar 19 12:37:37 2009 : Debug: Cleaning up request 4 ID 8 with timestamp
49c2206b</div>
<div>Thu Mar 19 12:37:37 2009 : Debug: Nothing to do. Sleeping until we
see a request.</div>
<div>Thu Mar 19 12:37:37 2009 : Debug: Threads: total/active/spare threads =
5/0/5</div>
</div>
<div><br /></div>
<div><br /></div>
<div>mikrotik ip </div>
<div>
<div>[admin@TEST-RADIUS] > ip address print </div>
<div>Flags: X - disabled, I - invalid, D - dynamic </div>
<div> # ADDRESS NETWORK
BROADCAST INTERFACE</div>
<div> 0 192.168.200.4/24 192.168.200.0 192.168.200.255
ether1 </div>
</div>
<div><br /></div>
<div>radius server ip`s</div>
<div><br /></div>
<div>
<div># ifconfig</div>
<div>eth0 Link encap:Ethernet HWaddr
00:19:66:4E:F4:E8</div>
<div> inet addr:192.168.200.3
Bcast:192.168.200.255 Mask:255.255.255.0</div>
<div> inet6 addr:
fe80::219:66ff:fe4e:f4e8/64 Scope:Link</div>
<div> UP BROADCAST RUNNING MULTICAST
MTU:1500 Metric:1</div>
<div> RX packets:67047606 errors:2
dropped:0 overruns:0 frame:0</div>
<div> TX packets:1327141 errors:0
dropped:0 overruns:0 carrier:0</div>
<div> collisions:0 txqueuelen:1000</div>
<div> RX bytes:480659514 (458.3 MiB)
TX bytes:570459851 (544.0 MiB)</div>
<div> Interrupt:17</div>
<div><br /></div>
<div>eth0:1 Link encap:Ethernet HWaddr
00:19:66:4E:F4:E8</div>
<div> inet addr:192.168.200.2
Bcast:192.168.200.255 Mask:255.255.255.0</div>
<div> UP BROADCAST RUNNING MULTICAST
MTU:1500 Metric:1</div>
<div> Interrupt:17</div>
<div><br /></div>
<div>eth0:3 Link encap:Ethernet HWaddr
00:19:66:4E:F4:E8</div>
<div> inet addr:212.70.XX.XX
Bcast:212.XX.XX.255 Mask:255.255.255.0</div>
<div> UP BROADCAST RUNNING MULTICAST
MTU:1500 Metric:1</div>
<div> Interrupt:17</div>
<div><br /></div>
<div>lo Link encap:Local Loopback</div>
<div> inet addr:127.0.0.1
Mask:255.0.0.0</div>
<div> inet6 addr: ::1/128
Scope:Host</div>
<div> UP LOOPBACK RUNNING MTU:16436
Metric:1</div>
<div> RX packets:37293 errors:0 dropped:0
overruns:0 frame:0</div>
<div> TX packets:37293 errors:0 dropped:0
overruns:0 carrier:0</div>
<div> collisions:0 txqueuelen:0</div>
<div> RX bytes:1787220 (1.7 MiB) TX
bytes:1787220 (1.7 MiB)</div>
<div><br /></div>
</div>
<div><span style="font-family: -webkit-monospace; font-size: 16px;
-webkit-border-horizontal-spacing: 2px; -webkit-border-vertical-spacing:
2px;">And watch as I can not understand where is the problem? </span><br
/></div>
<div><span style="font-family: -webkit-monospace; font-size: 16px;
-webkit-border-horizontal-spacing: 2px; -webkit-border-vertical-spacing:
2px;">Radius everything looks okay <br />More ideas?<br />Thank
you</span><br /></div>
<div><br /></div>
<div><br /></div>
<div><br /></div>
<div>P.S. witout firewall</div>
<div><br /></div>
<div>
<div># iptables -L -v</div>
<div>Chain INPUT (policy ACCEPT 0 packets, 0 bytes)</div>
<div> pkts bytes target prot opt in out
source destination</div>
<div><br /></div>
<div>Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)</div>
<div> pkts bytes target prot opt in out
source destination</div>
<div><br /></div>
<div>Chain OUTPUT (policy ACCEPT 0 packets, 0 bytes)</div>
<div> pkts bytes target prot opt in out
source destination</div>
</div>
<div><br /></div>
<div><br /></div>
<div>Thanks</div>
<br />
-- <br />Lazar Cherveniakov<br />Micro computers system - Lazkom<br />LIVE FREE
OR DIE<br /><br /><br />-------------------------------------<br />Powered by <a href="http://mail.bg">Mail.BG</a>