Hi all,
I am struggling with this issue right now. I have
installed a JRadius module on FreeRadius 1.1.0 , and
made FreeRadius to call the Jradius module in
post-auth section. The Jradius handler is supposed to
replace the access-accept packet obtained from prior
authentication with a access-challenge packet. My
logs show that rlm_jradius has correctly return
FreeRadius an Access-challenge module, with code 11.
However, Freeradius still returns an Access-accept to
the client (which is an radtest program). Does anyone
know what is the possible reason? Or maybe someone
can enlighten me as which part of the freeradius code
is actually handling this portion, so I can take a
look?
following is the debug output of freeradius: (the
dashed line and below are of the primary concern)
Thank you very much?
rad_recv: Access-Request packet from host
127.0.0.1:4820, id=197, length=64
User-Name = "hellouser123"
User-Password = "[EMAIL PROTECTED]"
NAS-IP-Address = 255.255.255.255
NAS-Port = 0
Wed Apr 5 11:51:50 2006 : Debug: Processing the
authorize section of radiusd.conf
Wed Apr 5 11:51:50 2006 : Debug: modcall: entering
group authorize for request 0
Wed Apr 5 11:51:50 2006 : Debug:
modsingle[authorize]: calling preprocess
(rlm_preprocess) for request 0
Wed Apr 5 11:51:50 2006 : Error: Invalid operator for
item Suffix: reverting to '=='
Wed Apr 5 11:51:50 2006 : Error: Invalid operator for
item Suffix: reverting to '=='
Wed Apr 5 11:51:50 2006 : Error: Invalid operator for
item Suffix: reverting to '=='
Wed Apr 5 11:51:50 2006 : Debug:
modsingle[authorize]: returned from preprocess
(rlm_preprocess) for request 0
Wed Apr 5 11:51:50 2006 : Debug:
modcall[authorize]: module "preprocess" returns ok for
request 0
Wed Apr 5 11:51:50 2006 : Debug:
modsingle[authorize]: calling ldap (rlm_ldap) for
request 0
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: -
authorize
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: performing
user authorization for hellouser123
Wed Apr 5 11:51:50 2006 : Debug: radius_xlat:
'(&(cn=hellouser123)(objectclass=user))'
Wed Apr 5 11:51:50 2006 : Debug: radius_xlat:
'cn=Users,dc=hellotechnology,dc=com'
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap:
ldap_get_conn: Checking Id: 0
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap:
ldap_get_conn: Got Id: 0
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: attempting
LDAP reconnection
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap:
(re)connect to 10.26.1.202:389, authentication 0
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: bind as
cn=krazy,cn=Users,dc=hellotechnology,dc=com/welcome123
to 10.26.1.202:389
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: waiting
for bind result ...
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: Bind was
successful
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: performing
search in cn=Users,dc=hellotechnology,dc=com, with
filter (&(cn=hellouser123)(objectclass=user))
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: checking
if remote access for hellouser123 is allowed by
msNPAllowDialin
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: looking
for check items in directory
...
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: looking
for reply items in directory...
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: user
hellouser123 authorized to use remote access
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap:
ldap_release_conn: Release Id: 0
Wed Apr 5 11:51:50 2006 : Debug:
modsingle[authorize]: returned from ldap (rlm_ldap)
for request 0
Wed Apr 5 11:51:50 2006 : Debug:
modcall[authorize]: module "ldap" returns ok for
request 0
Wed Apr 5 11:51:50 2006 : Debug: modcall: leaving
group authorize (returns ok) for request 0
Wed Apr 5 11:51:50 2006 : Debug:
rad_check_password: Found Auth-Type ldap
Wed Apr 5 11:51:50 2006 : Debug: auth: type "LDAP"
Wed Apr 5 11:51:50 2006 : Debug: Processing the
authenticate section of radiusd.conf
Wed Apr 5 11:51:50 2006 : Debug: modcall: entering
group LDAP for request 0
Wed Apr 5 11:51:50 2006 : Debug:
modsingle[authenticate]: calling ldap (rlm_ldap) for
request 0
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: -
authenticate
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: login
attempt by "hellouser123" with password "[EMAIL PROTECTED]"
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: user DN:
CN=hellouser123,CN=Users,DC=HelloTechnology,DC=com
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap:
(re)connect to 10.26.1.202:389, authentication 1
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: bind as
CN=hellouser123,CN=Users,DC=HelloTechnology,DC=com/[EMAIL PROTECTED]
to 10.26.1.202:389
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: waiting
for bind result ...
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: Bind was
successful
Wed Apr 5 11:51:50 2006 : Debug: rlm_ldap: user
hellouser123 authenticated succesfully
Wed Apr 5 11:51:50 2006 : Debug:
modsingle[authenticate]: returned from ldap (rlm_ldap)
for request 0
Wed Apr 5 11:51:50 2006 : Debug:
modcall[authenticate]: module "ldap" returns ok for
request 0
We