RE: Framed-IP user gets access-reject due to CHAP

14 Jan 2010

      It has been a while since I have used the users file having gone to MySQL,
but that about adding something like:

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.0,
	Fail-Through = Yes

The first line is the check items, the next lines are the reply items. You
have Framed-IP-Address as a check item not a reply item. Keep in mind that I
may have the syntax a bit wrong but the idea is to add some reply items to
assign the static IP instead of having the static IP as a check item.

-----Original Message-----
From: freeradius-users-bounces+hartwick=hartwick.com@lists.freeradius.org
[mailto:freeradius-users-bounces+hartwick=hartwick.com@lists.freeradius.org]
On Behalf Of Tevfik Ceydeliler
Sent: January 14, 2010 03:32
To: freeradius-users@lists.freeradius.org
Subject: Framed-IP user gets access-reject due to CHAP

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.

-
List info/subscribe/unsubscribe? See
http://www.freeradius.org/list/users.html

RE: Framed-IP user gets access-reject due to CHAP

Michael J. Hartwick