Everything looks fine in IP addresses, but the problem is still the same. 
Here again the log of Mikrotik and freeradius:
 
Mikrotik debug log
 
 
01:33:40 pppoe,info PPPoE connection established from 00:15:AF:1F:23:1A 
01:33:40 pppoe,ppp,info <pppoe-0>: waiting for call... 
01:33:40 radius,debug new request 53:02 code=Access-Request service=ppp called-id=pppoe-in 
01:33:40 radius,debug sending 53:02 to 192.168.200.2:1812 
01:33:40 radius,debug,packet sending Access-Request with id 8 to 192.168.200.2:1812 
01:33:40 radius,debug,packet     Signature = 0x83d0415d6b98f0421df6bb83a01bdb28 
01:33:40 radius,debug,packet     Service-Type = 2 
01:33:40 radius,debug,packet     Framed-Protocol = 1 
01:33:40 radius,debug,packet     NAS-Port = 10 
01:33:40 radius,debug,packet     NAS-Port-Type = 15 
01:33:40 radius,debug,packet     User-Name = "lacho" 
01:33:40 radius,debug,packet     Calling-Station-Id = "00:15:AF:1F:23:1A" 
01:33:40 radius,debug,packet     Called-Station-Id = "pppoe-in" 
01:33:40 radius,debug,packet     NAS-Port-Id = "ether1" 
01:33:40 radius,debug,packet     CHAP-Challenge = 0xe3c819400560adadbf019f209dc42f7e 
01:33:40 radius,debug,packet     CHAP-Password = 0x01dad26d1d56167a1899b3e9c8a8ba01 
01:33:40 radius,debug,packet       18 
01:33:40 radius,debug,packet     NAS-Identifier = "TEST-RADIUS" 
01:33:40 radius,debug,packet     NAS-IP-Address = 192.168.200.4 
01:33:41 radius,debug resending 53:02 
01:33:41 radius,debug,packet sending Access-Request with id 8 to 192.168.200.2:1812 
01:33:41 radius,debug,packet     Signature = 0x83d0415d6b98f0421df6bb83a01bdb28 
01:33:41 radius,debug,packet     Service-Type = 2 
01:33:41 radius,debug,packet     Framed-Protocol = 1 
01:33:41 radius,debug,packet     NAS-Port = 10 
01:33:41 radius,debug,packet     NAS-Port-Type = 15 
01:33:41 radius,debug,packet     User-Name = "lacho" 
01:33:41 radius,debug,packet     Calling-Station-Id = "00:15:AF:1F:23:1A" 
01:33:41 radius,debug,packet     Called-Station-Id = "pppoe-in" 
01:33:41 radius,debug,packet     NAS-Port-Id = "ether1" 
01:33:41 radius,debug,packet     CHAP-Challenge = 0xe3c819400560adadbf019f209dc42f7e 
01:33:41 radius,debug,packet     CHAP-Password = 0x01dad26d1d56167a1899b3e9c8a8ba01 
01:33:41 radius,debug,packet       18 
01:33:41 radius,debug,packet     NAS-Identifier = "TEST-RADIUS" 
01:33:41 radius,debug,packet     NAS-IP-Address = 192.168.200.4 
01:33:41 radius,debug resending 53:02 
01:33:41 radius,debug,packet sending Access-Request with id 8 to 192.168.200.2:1812 
01:33:41 radius,debug,packet     Signature = 0x83d0415d6b98f0421df6bb83a01bdb28 
01:33:41 radius,debug,packet     Service-Type = 2 
01:33:41 radius,debug,packet     Framed-Protocol = 1 
01:33:41 radius,debug,packet     NAS-Port = 10 
01:33:41 radius,debug,packet     NAS-Port-Type = 15 
01:33:41 radius,debug,packet     User-Name = "lacho" 
01:33:41 radius,debug,packet     Calling-Station-Id = "00:15:AF:1F:23:1A" 
01:33:41 radius,debug,packet     Called-Station-Id = "pppoe-in" 
01:33:41 radius,debug,packet     NAS-Port-Id = "ether1" 
01:33:41 radius,debug,packet     CHAP-Challenge = 0xe3c819400560adadbf019f209dc42f7e 
01:33:41 radius,debug,packet     CHAP-Password = 0x01dad26d1d56167a1899b3e9c8a8ba01 
01:33:41 radius,debug,packet       18 
01:33:41 radius,debug,packet     NAS-Identifier = "TEST-RADIUS" 
01:33:41 radius,debug,packet     NAS-IP-Address = 192.168.200.4 
01:33:41 radius,debug timeout for 53:02 
01:33:41 pppoe,ppp,info <pppoe-lacho>: terminating... - user lacho authentication failed - radius timeout (6) 
01:33:41 pppoe,ppp,info <pppoe-lacho>: disconnected 





Freeradius debug log:

Sending Access-Accept of id 7 to 192.168.200.4 port 32768
        Acct-Interim-Interval = 300
        Session-Timeout = 31
        Mikrotik-Xmit-Limit = 1073217536
        Framed-IP-Address = 10.8.15.44
        Mikrotik-Recv-Limit = 1073217536
        Framed-IP-Netmask = 255.255.255.255
Thu Mar 19 12:37:16 2009 : Debug: Finished request 3
Thu Mar 19 12:37:16 2009 : Debug: Going to the next request
Thu Mar 19 12:37:16 2009 : Debug: Thread 4 waiting to be assigned a request
rad_recv: Access-Request packet from host 192.168.200.4:32768, id=8, length=144
Thu Mar 19 12:37:31 2009 : Debug: --- Walking the entire request list ---
Thu Mar 19 12:37:31 2009 : Debug: Cleaning up request 3 ID 7 with timestamp 49c2205c
Thu Mar 19 12:37:31 2009 : Debug: Waking up in 31 seconds...
Thu Mar 19 12:37:31 2009 : Debug: Threads: total/active/spare threads = 5/0/5
Thu Mar 19 12:37:31 2009 : Debug: Thread 5 got semaphore
Thu Mar 19 12:37:31 2009 : Debug: Thread 5 handling request 4, (1 handled so far)
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 10
        NAS-Port-Type = Ethernet
        User-Name = "lacho"
        Calling-Station-Id = "00:15:AF:1F:23:1A"
        Called-Station-Id = "pppoe-in"
        NAS-Port-Id = "ether1"
        CHAP-Challenge = 0xe3c819400560adadbf019f209dc42f7e
        CHAP-Password = 0x01dad26d1d56167a1899b3e9c8a8ba0118
        NAS-Identifier = "TEST-RADIUS"
        NAS-IP-Address = 192.168.200.4
Thu Mar 19 12:37:31 2009 : Debug:   Processing the authorize section of radiusd.conf
Thu Mar 19 12:37:31 2009 : Debug: modcall: entering group authorize for request 4
Thu Mar 19 12:37:31 2009 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4
Thu Mar 19 12:37:31 2009 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4
Thu Mar 19 12:37:31 2009 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 4
Thu Mar 19 12:37:31 2009 : Debug:   modsingle[authorize]: calling pre_auth (rlm_exec) for request 4
Thu Mar 19 12:37:31 2009 : Debug: Exec-Program output: Auth-Type := Accept
Thu Mar 19 12:37:31 2009 : Debug: Exec-Program-Wait: value-pairs: Auth-Type := Accept
rad_recv: Access-Request packet from host 192.168.200.4:32768, id=8, length=144
Thu Mar 19 12:37:31 2009 : Error: Discarding duplicate request from client TEST-RADIUS:32768 - ID: 8 due to unfinished request 4
Thu Mar 19 12:37:31 2009 : Debug: rl_next:  returning NULL
Thu Mar 19 12:37:31 2009 : Debug: Waking up in 31 seconds...
Thu Mar 19 12:37:31 2009 : Debug: Threads: total/active/spare threads = 5/1/4
Thu Mar 19 12:37:32 2009 : Debug: Exec-Program: returned: 0
Thu Mar 19 12:37:32 2009 : Debug:   modsingle[authorize]: returned from pre_auth (rlm_exec) for request 4
Thu Mar 19 12:37:32 2009 : Debug:   modcall[authorize]: module "pre_auth" returns ok for request 4
Thu Mar 19 12:37:32 2009 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 4
Thu Mar 19 12:37:32 2009 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 4
Thu Mar 19 12:37:32 2009 : Debug:   modcall[authorize]: module "mschap" returns noop for request 4
Thu Mar 19 12:37:32 2009 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 4
Thu Mar 19 12:37:32 2009 : Debug:     users: Matched entry DEFAULT at line 52
Thu Mar 19 12:37:32 2009 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 4
Thu Mar 19 12:37:32 2009 : Debug:   modcall[authorize]: module "files" returns ok for request 4
Thu Mar 19 12:37:32 2009 : Debug: modcall: leaving group authorize (returns ok) for request 4
Thu Mar 19 12:37:32 2009 : Debug:   rad_check_password:  Found Auth-Type Accept
Thu Mar 19 12:37:32 2009 : Debug:   rad_check_password: Auth-Type = Accept, accepting the user
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,
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,
rad_recv: Access-Request packet from host 192.168.200.4:32768, id=8, length=144
Thu Mar 19 12:37:32 2009 : Error: Discarding duplicate request from client TEST-RADIUS:32768 - ID: 8 due to unfinished request 4
Thu Mar 19 12:37:32 2009 : Debug: --- Walking the entire request list ---
Thu Mar 19 12:37:32 2009 : Debug: Waking up in 5 seconds...
Thu Mar 19 12:37:32 2009 : Debug: Exec-Program: returned: 0
Sending Access-Accept of id 8 to 192.168.200.4 port 32768
        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
Thu Mar 19 12:37:32 2009 : Debug: Finished request 4
Thu Mar 19 12:37:32 2009 : Debug: Going to the next request
Thu Mar 19 12:37:32 2009 : Debug: Thread 5 waiting to be assigned a request
Thu Mar 19 12:37:37 2009 : Debug: --- Walking the entire request list ---
Thu Mar 19 12:37:37 2009 : Debug: Cleaning up request 4 ID 8 with timestamp 49c2206b
Thu Mar 19 12:37:37 2009 : Debug: Nothing to do.  Sleeping until we see a request.
Thu Mar 19 12:37:37 2009 : Debug: Threads: total/active/spare threads = 5/0/5


mikrotik ip 
[admin@TEST-RADIUS] > ip address print 
Flags: X - disabled, I - invalid, D - dynamic 
 #   ADDRESS            NETWORK         BROADCAST       INTERFACE
 0   192.168.200.4/24   192.168.200.0   192.168.200.255 ether1   

radius server ip`s

# ifconfig
eth0      Link encap:Ethernet  HWaddr 00:19:66:4E:F4:E8
          inet addr:192.168.200.3  Bcast:192.168.200.255  Mask:255.255.255.0
          inet6 addr: fe80::219:66ff:fe4e:f4e8/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:67047606 errors:2 dropped:0 overruns:0 frame:0
          TX packets:1327141 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:480659514 (458.3 MiB)  TX bytes:570459851 (544.0 MiB)
          Interrupt:17

eth0:1    Link encap:Ethernet  HWaddr 00:19:66:4E:F4:E8
          inet addr:192.168.200.2  Bcast:192.168.200.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          Interrupt:17

eth0:3    Link encap:Ethernet  HWaddr 00:19:66:4E:F4:E8
          inet addr:212.70.XX.XX  Bcast:212.XX.XX.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          Interrupt:17

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:37293 errors:0 dropped:0 overruns:0 frame:0
          TX packets:37293 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:1787220 (1.7 MiB)  TX bytes:1787220 (1.7 MiB)

And watch as I can not understand where is the problem? 
Radius everything looks okay 
More ideas?
Thank you



P.S. witout firewall

# iptables -L -v
Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination

Chain OUTPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination


Thanks
 
--
Lazar Cherveniakov
Micro computers system - Lazkom
LIVE FREE OR DIE


-------------------------------------
Powered by Mail.BG