Framed-IP user gets access-reject due to CHAP

Tevfik Ceydeliler tevfik.ceydeliler at astron.yasar.com.tr
Thu Jan 14 09:31:32 CET 2010


Hi list,
I have two types user. One of them get IP address from pool. Other one must use static IP address.
There is no problem with users use IP pool.
But users ,using static IP , get Access-Reject.
I have two debug output. And I use my account name to test. First I put my account into pooli then I put my account with static Ip address. In each tests I comment other raw.
Here is the users file :
-For Ip pool test:
tevfikceydeliler       Service-Type == Framed-User,Packet-Type==Access-Request, Proxy-To-Realm := 10.1.1.51, Pool-Name := BirmasGPRS_pool
#tevfikceydeliler       Packet-Type==Access-Request, Proxy-To-Realm := 10.1.1.51, Framed-IP-Address := 172.30.65.90, Framed-IP-Netmask := 255.255.240, Fall-Through = Yes

-For static IP test:
#tevfikceydeliler       Service-Type == Framed-User,Packet-Type==Access-Request, Proxy-To-Realm := 10.1.1.51, Pool-Name := BirmasGPRS_pool
tevfikceydeliler       Packet-Type==Access-Request, Proxy-To-Realm := 10.1.1.51, Framed-IP-Address := 172.30.65.90, Framed-IP-Netmask := 255.255.240, Fall-Through = Yes

I also have debug output for these two test:
-For Ip pool test:
rad_recv: Access-Request packet from host 172.30.80.1 port 1048, id=181, length=139
        NAS-IP-Address = 172.30.80.1
        NAS-Identifier = "GGFILE02"
        Called-Station-Id = "yasarapn"
        Framed-Protocol = GPRS-PDP-Context
        Service-Type = Framed-User
        NAS-Port-Type = Virtual
        NAS-Port = 119530800
        CHAP-Challenge = 0x084c2d1eb2b0da2fa88e86be50190074
        User-Name = "tevfikceydeliler"
        CHAP-Password = 0x01fe1f5c6c3340f451ba829a456b302ece
        Calling-Station-Id = "905308507313"
Thu Jan 14 10:05:39 2010 : Info: +- entering group authorize {...}
Thu Jan 14 10:05:39 2010 : Info: ++[preprocess] returns ok
Thu Jan 14 10:05:39 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/auth-detail-20100114
Thu Jan 14 10:05:39 2010 : Info: [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/auth-detail-20100114
Thu Jan 14 10:05:39 2010 : Debug:       expand: %t -> Thu Jan 14 10:05:39 2010
Thu Jan 14 10:05:39 2010 : Info: ++[auth_log] returns ok
Thu Jan 14 10:05:39 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:05:39 2010 : Info: [detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:05:39 2010 : Debug:       expand: %t -> Thu Jan 14 10:05:39 2010
Thu Jan 14 10:05:39 2010 : Info: ++[detail] returns ok
Thu Jan 14 10:05:39 2010 : Info: [chap] Setting 'Auth-Type := CHAP'
Thu Jan 14 10:05:39 2010 : Info: ++[chap] returns ok
Thu Jan 14 10:05:39 2010 : Info: ++[mschap] returns noop
Thu Jan 14 10:05:39 2010 : Info: [suffix] No '@' in User-Name = "tevfikceydeliler", looking up realm NULL
Thu Jan 14 10:05:39 2010 : Info: [suffix] No such realm "NULL"
Thu Jan 14 10:05:39 2010 : Info: ++[suffix] returns noop
Thu Jan 14 10:05:39 2010 : Info: [eap] No EAP-Message, not doing EAP
Thu Jan 14 10:05:39 2010 : Info: ++[eap] returns noop
Thu Jan 14 10:05:39 2010 : Info: ++[unix] returns notfound
Thu Jan 14 10:05:39 2010 : Info: [files] users: Matched entry tevfikceydeliler at line 114
Thu Jan 14 10:05:39 2010 : Debug:       expand: Hello, %{User-Name} -> Hello, tevfikceydeliler
Thu Jan 14 10:05:39 2010 : Info: ++[files] returns ok
Thu Jan 14 10:05:39 2010 : Info: ++[expiration] returns noop
Thu Jan 14 10:05:39 2010 : Info: ++[logintime] returns noop
Thu Jan 14 10:05:39 2010 : Info: +- entering group pre-proxy {...}
Thu Jan 14 10:05:39 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/pre-proxy-detail-20100114
Thu Jan 14 10:05:39 2010 : Info: [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/pre-proxy-detail-20100114
Thu Jan 14 10:05:39 2010 : Debug:       expand: %t -> Thu Jan 14 10:05:39 2010
Thu Jan 14 10:05:39 2010 : Info: ++[pre_proxy_log] returns ok
Thu Jan 14 10:05:39 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:05:39 2010 : Info: [detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:05:39 2010 : Debug:       expand: %t -> Thu Jan 14 10:05:39 2010
Thu Jan 14 10:05:39 2010 : Info: ++[detail] returns ok
Sending Access-Request of id 218 to 10.1.1.51 port 1812
        NAS-IP-Address = 172.30.80.1
        NAS-Identifier = "GGFILE02"
        Called-Station-Id = "yasarapn"
        Framed-Protocol = GPRS-PDP-Context
        Service-Type = Framed-User
        NAS-Port-Type = Virtual
        NAS-Port = 119530800
        CHAP-Challenge = 0x084c2d1eb2b0da2fa88e86be50190074
        User-Name = "tevfikceydeliler"
        CHAP-Password = 0x01fe1f5c6c3340f451ba829a456b302ece
        Calling-Station-Id = "905308507313"
        Proxy-State = 0x313831
Thu Jan 14 10:05:39 2010 : Info: Proxying request 0 to home server 10.1.1.51 port 1812
Sending Access-Request of id 218 to 10.1.1.51 port 1812
        NAS-IP-Address = 172.30.80.1
        NAS-Identifier = "GGFILE02"
        Called-Station-Id = "yasarapn"
        Framed-Protocol = GPRS-PDP-Context
        Service-Type = Framed-User
        NAS-Port-Type = Virtual
        NAS-Port = 119530800
        CHAP-Challenge = 0x084c2d1eb2b0da2fa88e86be50190074
        User-Name = "tevfikceydeliler"
        CHAP-Password = 0x01fe1f5c6c3340f451ba829a456b302ece
        Calling-Station-Id = "905308507313"
        Proxy-State = 0x313831
Thu Jan 14 10:05:39 2010 : Debug: Going to the next request
Thu Jan 14 10:05:39 2010 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Accept packet from host 10.1.1.51 port 1812, id=218, length=25
        Proxy-State = 0x313831
Thu Jan 14 10:05:39 2010 : Info: +- entering group post-proxy {...}
Thu Jan 14 10:05:39 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/post-proxy-detail-20100114
Thu Jan 14 10:05:39 2010 : Info: [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/post-proxy-detail-20100114
Thu Jan 14 10:05:39 2010 : Debug:       expand: %t -> Thu Jan 14 10:05:39 2010
Thu Jan 14 10:05:39 2010 : Info: ++[post_proxy_log] returns ok
Thu Jan 14 10:05:39 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:05:39 2010 : Info: [detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:05:39 2010 : Debug:       expand: %t -> Thu Jan 14 10:05:39 2010
Thu Jan 14 10:05:39 2010 : Info: ++[detail] returns ok
Thu Jan 14 10:05:39 2010 : Info: [eap] No pre-existing handler found
Thu Jan 14 10:05:39 2010 : Info: ++[eap] returns noop
Thu Jan 14 10:05:39 2010 : Info: Found Auth-Type = CHAP
Thu Jan 14 10:05:39 2010 : Info: Found Auth-Type = Accept
Thu Jan 14 10:05:39 2010 : Error: Warning:  Found 2 auth-types on request for user 'tevfikceydeliler'
Thu Jan 14 10:05:39 2010 : Info: Auth-Type = Accept, accepting the user
Thu Jan 14 10:05:39 2010 : Auth: Login OK: [tevfikceydeliler/<CHAP-Password>] (from client turkcellAPN port 119530800 cli 905308507313)
Thu Jan 14 10:05:39 2010 : Info: +- entering group post-auth {...}
Thu Jan 14 10:05:39 2010 : Info: ++[TCELL_pool] returns noop
Thu Jan 14 10:05:39 2010 : Debug:       expand: %{NAS-IP-Address} %{NAS-Port} -> 172.30.80.1 119530800
Thu Jan 14 10:05:39 2010 : Info: [BirmasGPRS_pool] MD5 on 'key' directive maps to: 860ffa91b70d5bb8b649d5ee042c87ea
Thu Jan 14 10:05:39 2010 : Info: [BirmasGPRS_pool] Searching for an entry for key: '860ffa91b70d5bb8b649d5ee042c87ea'
Thu Jan 14 10:05:39 2010 : Debug: rlm_ippool: Allocating ip to key: '860ffa91b70d5bb8b649d5ee042c87ea'
Thu Jan 14 10:05:39 2010 : Info: [BirmasGPRS_pool] num: 1
Thu Jan 14 10:05:39 2010 : Info: [BirmasGPRS_pool] Allocated ip 172.30.64.80 to client key: 860ffa91b70d5bb8b649d5ee042c87ea
Thu Jan 14 10:05:39 2010 : Info: ++[BirmasGPRS_pool] returns ok
Thu Jan 14 10:05:39 2010 : Info: ++[PSUOtonom_pool] returns noop
Thu Jan 14 10:05:39 2010 : Info: ++[YBPOtonom1_pool] returns noop
Thu Jan 14 10:05:39 2010 : Info: ++[YBPOtonom2_pool] returns noop
Thu Jan 14 10:05:39 2010 : Info: ++[YBPOtonom3_pool] returns noop
Thu Jan 14 10:05:39 2010 : Info: ++[Turkcell3G_pool] returns noop
Thu Jan 14 10:05:39 2010 : Info: ++[PsuYBP2Ortak_pool] returns noop
Thu Jan 14 10:05:39 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/reply-detail-20100114
Thu Jan 14 10:05:39 2010 : Info: [reply_log] /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/reply-detail-20100114
Thu Jan 14 10:05:39 2010 : Debug:       expand: %t -> Thu Jan 14 10:05:39 2010
Thu Jan 14 10:05:39 2010 : Info: ++[reply_log] returns ok
Thu Jan 14 10:05:39 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:05:39 2010 : Info: [detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:05:39 2010 : Debug:       expand: %t -> Thu Jan 14 10:05:39 2010
Thu Jan 14 10:05:39 2010 : Info: ++[detail] returns ok
Thu Jan 14 10:05:39 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 181 to 172.30.80.1 port 1048
        Framed-IP-Address = 172.30.64.80
        Framed-IP-Netmask = 255.255.240.0
Thu Jan 14 10:05:39 2010 : Info: Finished request 0.
Thu Jan 14 10:05:39 2010 : Debug: Going to the next request
Thu Jan 14 10:05:39 2010 : Debug: Waking up in 4.9 seconds.
Thu Jan 14 10:05:44 2010 : Info: Cleaning up request 0 ID 181 with timestamp +45
Thu Jan 14 10:05:44 2010 : Debug: Ready to process requests.

-For Static IP test:
rad_recv: Access-Request packet from host 172.30.80.1 port 3820, id=232, length=139
        NAS-IP-Address = 172.30.80.1
        NAS-Identifier = "GGFILE02"
        Called-Station-Id = "yasarapn"
        Framed-Protocol = GPRS-PDP-Context
        Service-Type = Framed-User
        NAS-Port-Type = Virtual
        NAS-Port = 32285232
        CHAP-Challenge = 0xae0e7eb20e1df67194bcedd4c205f843
        User-Name = "tevfikceydeliler"
        CHAP-Password = 0x01fb5a4bf58cd585c42cde13b49b6ae11b
        Calling-Station-Id = "905308507313"
Thu Jan 14 10:07:46 2010 : Info: +- entering group authorize {...}
Thu Jan 14 10:07:46 2010 : Info: ++[preprocess] returns ok
Thu Jan 14 10:07:46 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/auth-detail-20100114
Thu Jan 14 10:07:46 2010 : Info: [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/auth-detail-20100114
Thu Jan 14 10:07:46 2010 : Debug:       expand: %t -> Thu Jan 14 10:07:46 2010
Thu Jan 14 10:07:46 2010 : Info: ++[auth_log] returns ok
Thu Jan 14 10:07:46 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:07:46 2010 : Info: [detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:07:46 2010 : Debug:       expand: %t -> Thu Jan 14 10:07:46 2010
Thu Jan 14 10:07:46 2010 : Info: ++[detail] returns ok
Thu Jan 14 10:07:46 2010 : Info: [chap] Setting 'Auth-Type := CHAP'
Thu Jan 14 10:07:46 2010 : Info: ++[chap] returns ok
Thu Jan 14 10:07:46 2010 : Info: ++[mschap] returns noop
Thu Jan 14 10:07:46 2010 : Info: [suffix] No '@' in User-Name = "tevfikceydeliler", looking up realm NULL
Thu Jan 14 10:07:46 2010 : Info: [suffix] No such realm "NULL"
Thu Jan 14 10:07:46 2010 : Info: ++[suffix] returns noop
Thu Jan 14 10:07:46 2010 : Info: [eap] No EAP-Message, not doing EAP
Thu Jan 14 10:07:46 2010 : Info: ++[eap] returns noop
Thu Jan 14 10:07:46 2010 : Info: ++[unix] returns notfound
Thu Jan 14 10:07:46 2010 : Info: ++[files] returns noop
Thu Jan 14 10:07:46 2010 : Info: ++[expiration] returns noop
Thu Jan 14 10:07:46 2010 : Info: ++[logintime] returns noop
Thu Jan 14 10:07:46 2010 : Info: Found Auth-Type = CHAP
Thu Jan 14 10:07:46 2010 : Info: +- entering group CHAP {...}
Thu Jan 14 10:07:46 2010 : Info: [chap] login attempt by "tevfikceydeliler" with CHAP password
Thu Jan 14 10:07:46 2010 : Info: [chap] Cleartext-Password is required for authentication
Thu Jan 14 10:07:46 2010 : Info: ++[chap] returns invalid
Thu Jan 14 10:07:46 2010 : Info: Failed to authenticate the user.
Thu Jan 14 10:07:46 2010 : Auth: Login incorrect (rlm_chap: Clear text password not available): [tevfikceydeliler/<CHAP-Password>] (from client turkcellAPN port 32285232 cli 905308507313)
Thu Jan 14 10:07:46 2010 : Info: Using Post-Auth-Type Reject
Thu Jan 14 10:07:46 2010 : Info: +- entering group REJECT {...}
Thu Jan 14 10:07:46 2010 : Debug:       expand: %{User-Name} -> tevfikceydeliler
Thu Jan 14 10:07:46 2010 : Debug:  attr_filter: Matched entry DEFAULT at line 11
Thu Jan 14 10:07:46 2010 : Info: ++[attr_filter.access_reject] returns updated
Thu Jan 14 10:07:46 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:07:46 2010 : Info: [detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/detail-20100114
Thu Jan 14 10:07:46 2010 : Debug:       expand: %t -> Thu Jan 14 10:07:46 2010
Thu Jan 14 10:07:46 2010 : Info: ++[detail] returns ok
Thu Jan 14 10:07:46 2010 : Debug:       expand: /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/log/freeradius/radacct/172.30.80.1/reply-detail-20100114
Thu Jan 14 10:07:46 2010 : Info: [reply_log] /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/freeradius/radacct/172.30.80.1/reply-detail-20100114
Thu Jan 14 10:07:46 2010 : Debug:       expand: %t -> Thu Jan 14 10:07:46 2010
Thu Jan 14 10:07:46 2010 : Info: ++[reply_log] returns ok
Thu Jan 14 10:07:46 2010 : Info: Delaying reject of request 0 for 3 seconds
Thu Jan 14 10:07:46 2010 : Debug: Going to the next request
Thu Jan 14 10:07:46 2010 : Debug: Waking up in 0.9 seconds.
Thu Jan 14 10:07:47 2010 : Debug: Waking up in 1.9 seconds.
Thu Jan 14 10:07:49 2010 : Info: Sending delayed reject for request 0
Sending Access-Reject of id 232 to 172.30.80.1 port 3820
Thu Jan 14 10:07:49 2010 : Debug: Waking up in 4.9 seconds.
Thu Jan 14 10:07:54 2010 : Info: Cleaning up request 0 ID 232 with timestamp +52
Thu Jan 14 10:07:54 2010 : Debug: Ready to process requests.

There is some raw differet ofcourse:
The test for IP Pool, conenction request enter preproxy. But test for static IP conenction goes directly "Auth-Type := CHAP". So the problem begins after this , because I get following messages:
Thu Jan 14 10:07:46 2010 : Info: [chap] login attempt by "tevfikceydeliler" with CHAP password
Thu Jan 14 10:07:46 2010 : Info: [chap] Cleartext-Password is required for authentication
Thu Jan 14 10:07:46 2010 : Info: ++[chap] returns invalid
Thu Jan 14 10:07:46 2010 : Info: Failed to authenticate the user.
Thu Jan 14 10:07:46 2010 : Auth: Login incorrect (rlm_chap: Clear text password not available): [tevfikceydeliler/<CHAP-Password>] (from client turkcellAPN port 32285232 cli 905308507313)

I know that my IP pool names located in ../sites-enabled/default file under accounting and post-auth section.
Question is where can I put my user ,using static IP, that freeraidus behave like my user is IP pool user?
I lost my way. I read many list posts but I can get a appropriate answer.
Regards.

Tevfik Ceydeliler
  



Bu elektronik postada bulunan tum fikir ve gorusler ve ekindeki dosyalar sadece adres sahip/sahiplerine ait olup, Yasar Toplulugu Sirketleri bu mesajin icerigi ile ilgili olarak hic bir hukuksal sorumlulugu kabul etmez. Eger gonderilmesi dusunulen kisi veya kurulus degilseniz, lutfen gonderen kisiyi derhal haberdar ediniz ve mesaji sisteminizden siliniz.The information contained in this e-mail and any files transmitted with it are intended solely for the use of the individual or entity to whom they are addressed and Yasar Group Companies do not accept legal responsibility for the contents. If you are not the intended recipient, please immediately notify the sender and delete it from your system.




More information about the Freeradius-Users mailing list