weird error
Joe Vieira
jvieira at clarku.edu
Fri Feb 8 15:20:19 CET 2008
Is anyone else running freeradius 2.0.1 on rhel5 x86-64?
I am consistently getting a segfault (~every 45minutes or so) from line
1319 of rlm_ldap.c , gdb debugging shows me that vals[0] is not a valid
memory location. (always 0xffffffffb00020e0)
this occurs on two physically different servers (different make and
model as well)
this only seems to occur when the server is run THREADED, when i run in
`radiusd -X` it DOES NOT segfault. however in `radiusd -fxxxx`
(threaded debug) it DOES segfault
attached seems to be the request that is causing a segfault....
(threaded debug mode) as well as a backtrace and some other gdb info.
rad_recv: Access-Request packet from host 10.5.5.3 port 32770, id=198,
length=192
Fri Feb 8 08:55:09 2008 : Debug: Waking up in 0.9 seconds.
Fri Feb 8 08:55:09 2008 : Debug: Thread 8 got semaphore
Fri Feb 8 08:55:09 2008 : Debug: Thread 8 handling request 1112, (139
handled so far)
User-Name = "STUDENTS\\kcook"
Calling-Station-Id = "00-90-96-C7-15-7C"
Called-Station-Id = "00-19-07-06-68-40:ClarkWiFi"
NAS-Port = 29
NAS-IP-Address = 10.5.5.3
NAS-Identifier = "WISM1-8B"
Airespace-Wlan-Id = 2
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "177"
EAP-Message = 0x023e00130153545544454e54535c6b636f6f6b
Message-Authenticator = 0xa49c3013a1518db03e9dd79520678670
Fri Feb 8 08:55:09 2008 : Debug: +- entering group authorize
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: hints: Matched DEFAULT at 65
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for reques
t 1112
Fri Feb 8 08:55:09 2008 : Debug: ++[preprocess] returns ok
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
mschap (rlm_mschap) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: ++[mschap] returns noop
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: EAP packet type response id
62 length 19
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
eap (rlm_eap) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: ++[eap] returns updated
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: users: Matched entry DEFAULT at
line 17
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: Entering ldap_groupcmp()
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(uid=%{mschap:User-Name}) -> (uid=kcook)
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
ou=Users, dc=clarku, dc=edu , with filter (ui
d=kcook)
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(&(objectClass=posixGroup)(memberUid=%{mschap:User-Name})) ->
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
cn=Administrators,ou=Groups,dc=clarku,dc=edu,
with filter (&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: object not found or got
ambiguous search result
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap::ldap_groupcmp: Group
cn=Administrators,ou=Groups,dc=clarku,dc=edu
not found or user is not a member.
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: Entering ldap_groupcmp()
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(&(objectClass=posixGroup)(memberUid=%{mschap:User-Name})) ->
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
cn=ITS_Staff,ou=groups,dc=clarku,dc=edu, with
filter (&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: object not found or got
ambiguous search result
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap::ldap_groupcmp: Group
cn=ITS_Staff,ou=groups,dc=clarku,dc=edu not f
ound or user is not a member.
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: Entering ldap_groupcmp()
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(&(objectClass=posixGroup)(memberUid=%{mschap:User-Name})) ->
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
cn=Idrisi,ou=groups,dc=clarku,dc=edu, with fi
lter (&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: object not found or got
ambiguous search result
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap::ldap_groupcmp: Group
cn=Idrisi,ou=groups,dc=clarku,dc=edu not foun
d or user is not a member.
Fri Feb 8 08:55:09 2008 : Debug: users: Matched entry DEFAULT at
line 46
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
files (rlm_files) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: ++[files] returns ok
Fri Feb 8 08:55:09 2008 : Debug: Found Autz-Type WIRELESS
Fri Feb 8 08:55:09 2008 : Debug: +- entering group WIRELESS
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling
wirlss_erebus (rlm_ldap) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: - authorize
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing user
authorization for STUDENTS\kcook
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(uid=%{mschap:User-Name}) -> (uid=kcook)
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
ou=Users, dc=clarku, dc=edu , with filter (ui
d=kcook)
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: checking if remote access
for STUDENTS\kcook is allowed by clarkuW
irelessAccess
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: looking for check items in
directory...
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: LDAP attribute acctFlags as
RADIUS attribute SMB-Account-CTRL-TEXT
== "[UX ]"
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: LDAP attribute ntPassword as
RADIUS attribute NT-Password == 0x453
2413742414631434436454630303242423643393134394141343135303241
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: LDAP attribute lmPassword as
RADIUS attribute LM-Password == 0x323
9434135333838313132374541413233363037374137313843434446343039
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: looking for reply items in
directory...
Fri Feb 8 08:55:09 2008 : Debug: WARNING: No "known good" password was
found in LDAP. Are you sure that the
user is configured correctly?
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: user STUDENTS\kcook
authorized to use remote access
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
wirlss_erebus (rlm_ldap) for request 1
112
Fri Feb 8 08:55:09 2008 : Debug: ++[wirlss_erebus] returns ok
Fri Feb 8 08:55:09 2008 : Debug: rad_check_password: Found Auth-Type EAP
Fri Feb 8 08:55:09 2008 : Debug: auth: type "EAP"
Fri Feb 8 08:55:09 2008 : Debug: +- entering group authenticate
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authenticate]: calling eap
(rlm_eap) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: EAP Identity
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: processing type tls
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_tls: Initiate
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_tls: Start returned 1
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authenticate]: returned
from eap (rlm_eap) for request 1112
Fri Feb 8 08:55:09 2008 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 198 to 10.5.5.3 port 32770
Reply-Message = "Welcome %u, to Clark University's network
#AUTHORIZED USE ONLY#"
Tunnel-Private-Group-Id:0 = "177"
EAP-Message = 0x013f00061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x00000000003f19000000000000000000
Fri Feb 8 08:55:09 2008 : Debug: Finished request 1112.
Fri Feb 8 08:55:09 2008 : Debug: Going to the next request
Fri Feb 8 08:55:09 2008 : Debug: Thread 8 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.5.5.3 port 32770, id=199,
length=303
Fri Feb 8 08:55:09 2008 : Debug: Waking up in 0.9 seconds.
Fri Feb 8 08:55:09 2008 : Debug: Thread 3 got semaphore
Fri Feb 8 08:55:09 2008 : Debug: Thread 3 handling request 1113, (140
handled so far)
User-Name = "STUDENTS\\kcook"
Calling-Station-Id = "00-90-96-C7-15-7C"
Called-Station-Id = "00-19-07-06-68-40:ClarkWiFi"
NAS-Port = 29
NAS-IP-Address = 10.5.5.3
NAS-Identifier = "WISM1-8B"
Airespace-Wlan-Id = 2
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "177"
EAP-Message =
0x023f007019800000006616030100610100005d030147ac5f3c5179e17d35b42bc56df35948036b613210aa
debf5f96d9e2faad5884202e2d387d86b210c5bbdf85b23ec813d4d267822e615dc82a424ea0f3c505779f001600040005000a00090064
0062000300060013001200630100
State = 0x00000000003f19000000000000000000
Message-Authenticator = 0xf579dbd1bdc44c5815dfdb87e1ad17e3
Fri Feb 8 08:55:09 2008 : Debug: +- entering group authorize
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: hints: Matched DEFAULT at 65
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for reques
t 1113
Fri Feb 8 08:55:09 2008 : Debug: ++[preprocess] returns ok
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
mschap (rlm_mschap) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: ++[mschap] returns noop
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: EAP packet type response id
63 length 112
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: Continuing tunnel setup.
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
eap (rlm_eap) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: ++[eap] returns ok
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: users: Matched entry DEFAULT at
line 17
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: Entering ldap_groupcmp()
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(uid=%{mschap:User-Name}) -> (uid=kcook)
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
ou=Users, dc=clarku, dc=edu , with filter (ui
d=kcook)
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(&(objectClass=posixGroup)(memberUid=%{mschap:User-Name})) ->
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
cn=Administrators,ou=Groups,dc=clarku,dc=edu,
with filter (&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: object not found or got
ambiguous search result
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap::ldap_groupcmp: Group
cn=Administrators,ou=Groups,dc=clarku,dc=edu
not found or user is not a member.
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: Entering ldap_groupcmp()
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(&(objectClass=posixGroup)(memberUid=%{mschap:User-Name})) ->
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
cn=ITS_Staff,ou=groups,dc=clarku,dc=edu, with
filter (&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: object not found or got
ambiguous search result
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap::ldap_groupcmp: Group
cn=ITS_Staff,ou=groups,dc=clarku,dc=edu not f
ound or user is not a member.
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: Entering ldap_groupcmp()
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(&(objectClass=posixGroup)(memberUid=%{mschap:User-Name})) ->
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
cn=Idrisi,ou=groups,dc=clarku,dc=edu, with fi
lter (&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: object not found or got
ambiguous search result
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap::ldap_groupcmp: Group
cn=Idrisi,ou=groups,dc=clarku,dc=edu not foun
d or user is not a member.
Fri Feb 8 08:55:09 2008 : Debug: users: Matched entry DEFAULT at
line 46
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
files (rlm_files) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: ++[files] returns ok
Fri Feb 8 08:55:09 2008 : Debug: Found Autz-Type WIRELESS
Fri Feb 8 08:55:09 2008 : Debug: +- entering group WIRELESS
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling
wirlss_erebus (rlm_ldap) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: - authorize
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing user
authorization for STUDENTS\kcook
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'U
ser-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(uid=%{mschap:User-Name}) -> (uid=kcook)
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
ou=Users, dc=clarku, dc=edu , with filter (ui
d=kcook)
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: checking if remote access
for STUDENTS\kcook is allowed by clarkuW
irelessAccess
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: looking for check items in
directory...
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: LDAP attribute acctFlags as
RADIUS attribute SMB-Account-CTRL-TEXT
== "[UX ]"
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: LDAP attribute ntPassword as
RADIUS attribute NT-Password == 0x453
2413742414631434436454630303242423643393134394141343135303241
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: LDAP attribute lmPassword as
RADIUS attribute LM-Password == 0x323
9434135333838313132374541413233363037374137313843434446343039
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: looking for reply items in
directory...
Fri Feb 8 08:55:09 2008 : Debug: WARNING: No "known good" password was
found in LDAP. Are you sure that the
user is configured correctly?
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: user STUDENTS\kcook
authorized to use remote access
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
wirlss_erebus (rlm_ldap) for request 1
113
Fri Feb 8 08:55:09 2008 : Debug: ++[wirlss_erebus] returns ok
Fri Feb 8 08:55:09 2008 : Debug: rad_check_password: Found Auth-Type EAP
Fri Feb 8 08:55:09 2008 : Debug: auth: type "EAP"
Fri Feb 8 08:55:09 2008 : Debug: +- entering group authenticate
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authenticate]: calling eap
(rlm_eap) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: Request found, released
from the list
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: EAP/peap
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: processing type peap
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_peap: Authenticate
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_tls: processing TLS
Fri Feb 8 08:55:09 2008 : Debug: TLS Length 102
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_tls: Length Included
Fri Feb 8 08:55:09 2008 : Debug: eaptls_verify returned 11
Fri Feb 8 08:55:09 2008 : Debug: (other): before/accept initialization
Fri Feb 8 08:55:09 2008 : Debug: TLS_accept: before/accept
initialization
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake
[length 0061], ClientHello
Fri Feb 8 08:55:09 2008 : Debug: TLS_accept: SSLv3 read client hello A
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake
[length 004a], ServerHello
Fri Feb 8 08:55:09 2008 : Debug: TLS_accept: SSLv3 write server hello A
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake
[length 02f6], Certificate
Fri Feb 8 08:55:09 2008 : Debug: TLS_accept: SSLv3 write certificate A
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake
[length 0004], ServerHelloDone
Fri Feb 8 08:55:09 2008 : Debug: TLS_accept: SSLv3 write server done A
Fri Feb 8 08:55:09 2008 : Debug: TLS_accept: SSLv3 flush data
Fri Feb 8 08:55:09 2008 : Debug: TLS_accept: Need to read more
data: SSLv3 read client certificate A
Fri Feb 8 08:55:09 2008 : Debug: In SSL Handshake Phase
Fri Feb 8 08:55:09 2008 : Debug: In SSL Accept mode
Fri Feb 8 08:55:09 2008 : Debug: eaptls_process returned 13
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap_peap: EAPTLS_HANDLED
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authenticate]: returned
from eap (rlm_eap) for request 1113
Fri Feb 8 08:55:09 2008 : Debug: ++[eap] returns handled
Sending Access-Challenge of id 199 to 10.5.5.3 port 32770
Reply-Message = "Welcome %u, to Clark University's network
#AUTHORIZED USE ONLY#"
Tunnel-Private-Group-Id:0 = "177"
EAP-Message =
0x014003591900160301004a02000046030147ac5f3da6e97785406e9452b989754ea503af327c691c27dce6
65d64ff4616c20e95922022ef4cb7c0d43ee3ad781f42936ae850d6572456fc5bf0c3480b9808e00040016030102f60b0002f20002ef00
02ec308202e830820251a0030201020203078e97300d06092a864886f70d0101050500304e310b30090603550406130255533110300e06
0355040a130745717569666178312d302b060355040b132445717569666178205365637572652043657274696669636174652041757468
6f72697479301e170d3037303631313135323131355a170d3039303631313135323131355a3073310b30090603
EAP-Message =
0x55040613025553311630140603550408130d4d617373616368757365747473311230100603550407130957
6f7263657374657231193017060355040a1310436c61726b20556e6976657273697479311d301b060355040313147261646975732e6974
2e636c61726b752e65647530819f300d06092a864886f70d010101050003818d0030818902818100c3ae41e4a71f4c0b9571dd8820a7c8
cdfbee310216157ec0c9bd84980dc83e770a497addcba409b050ff528bc349c7ad6d91c84ce18618e93ec08ec8a1456c1c2ae405d58105
cebc68df124389451338ff0ded9d98ecb2b4c88a626081a834c9a464a8428451383ac681c63ba253761da2cd7b
EAP-Message =
0x16b3c23f5f7fcecef587971e570203010001a381ae3081ab300e0603551d0f0101ff0404030204f0301d06
03551d0e04160414b1dc00af1a89c7939f9b382619cc9f1f8edfaf59303a0603551d1f04333031302fa02da02b8629687474703a2f2f63
726c2e67656f74727573742e636f6d2f63726c732f73656375726563612e63726c301f0603551d2304183016801448e668f92bd2b295d7
47d82320104f3398909fd4301d0603551d250416301406082b0601050507030106082b06010505070302300d06092a864886f70d010105
050003818100258c15a8e13b417f09719aa339b5d8ff4b38df6607d6441ce41653ffdc29b742acee64a3df671e
EAP-Message =
0xc31ec0c96d3b48d004af81f38087e32655d9ca8bcc93a11c2b9a0fff6118e1c78b5ff8860b038e541d7555
d0e3f47a6e972f8a672eca7e4de1af549bd879c25c4c08ee57525859c065b6296bb0dffdfb9ca4a4ac083c03a1d616030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x00000000014019000000000000000000
Fri Feb 8 08:55:09 2008 : Debug: Finished request 1113.
Fri Feb 8 08:55:09 2008 : Debug: Going to the next request
Fri Feb 8 08:55:09 2008 : Debug: Thread 3 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.5.5.3 port 32770, id=200,
length=383
Fri Feb 8 08:55:09 2008 : Debug: Waking up in 0.9 seconds.
Fri Feb 8 08:55:09 2008 : Debug: Thread 1 got semaphore
Fri Feb 8 08:55:09 2008 : Debug: Thread 1 handling request 1114, (140
handled so far)
User-Name = "STUDENTS\\kcook"
Calling-Station-Id = "00-90-96-C7-15-7C"
Called-Station-Id = "00-19-07-06-68-40:ClarkWiFi"
NAS-Port = 29
NAS-IP-Address = 10.5.5.3
NAS-Identifier = "WISM1-8B"
Airespace-Wlan-Id = 2
Service-Type = Framed-User
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "177"
EAP-Message =
0x024000c01980000000b6160301008610000082008048a1b8f7224e5687bab7781160089c293dc10d9a7666
5b16ad5d8f924f5c2b056e2080978b26291221b5e67e4250efd2d2476c01f4fa1b6cd5ee14876aeca84eb032473c89693458fffa60787e
a4352a2f70e24c949e7d464d28b894d60f9f52ca35ca022f8d4ed0236332bb33ce9f804eef044740f4d4ec9353eb81b56cd30a14030100
01011603010020ee3e58c58f4a09c290c273c058353b50d4ec407155a3b8086ffc3b3e047e05dc
State = 0x00000000014019000000000000000000
Message-Authenticator = 0x810656c4ecaf53974ec51e777f956ea5
Fri Feb 8 08:55:09 2008 : Debug: +- entering group authorize
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 1114
Fri Feb 8 08:55:09 2008 : Debug: hints: Matched DEFAULT at 65
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 1114
Fri Feb 8 08:55:09 2008 : Debug: ++[preprocess] returns ok
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 1114
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
mschap (rlm_mschap) for request 1114
Fri Feb 8 08:55:09 2008 : Debug: ++[mschap] returns noop
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 1114
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: EAP packet type response id
64 length 192
Fri Feb 8 08:55:09 2008 : Debug: rlm_eap: Continuing tunnel setup.
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
eap (rlm_eap) for request 1114
Fri Feb 8 08:55:09 2008 : Debug: ++[eap] returns ok
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 1114
Fri Feb 8 08:55:09 2008 : Debug: users: Matched entry DEFAULT at
line 17
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: Entering ldap_groupcmp()
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'User-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(uid=%{mschap:User-Name}) -> (uid=kcook)
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
ou=Users, dc=clarku, dc=edu , with filter (uid=kcook)
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'User-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(&(objectClass=posixGroup)(memberUid=%{mschap:User-Name}))
->
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
cn=Administrators,ou=Groups,dc=clarku,dc=edu, with filter
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: object not found or got
ambiguous search result
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap::ldap_groupcmp: Group
cn=Administrators,ou=Groups,dc=clarku,dc=edu not found or user is not a
member.
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: Entering ldap_groupcmp()
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'User-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(&(objectClass=posixGroup)(memberUid=%{mschap:User-Name}))
->
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
cn=ITS_Staff,ou=groups,dc=clarku,dc=edu, with ilter
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: object not found or got
ambiguous search result
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap::ldap_groupcmp: Group
cn=ITS_Staff,ou=groups,dc=clarku,dc=edu not found or user is not a member.
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: Entering ldap_groupcmp()
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'User-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(&(objectClass=posixGroup)(memberUid=%{mschap:User-Name}))
->
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
cn=Idrisi,ou=groups,dc=clarku,dc=edu, with filter
(&(objectClass=posixGroup)(memberUid=kcook))
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: object not found or got
ambiguous search result
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap::ldap_groupcmp: Group
cn=Idrisi,ou=groups,dc=clarku,dc=edu not found or user is not a member.
Fri Feb 8 08:55:09 2008 : Debug: users: Matched entry DEFAULT at
line 46
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: returned from
files (rlm_files) for request 1114
Fri Feb 8 08:55:09 2008 : Debug: ++[files] returns ok
Fri Feb 8 08:55:09 2008 : Debug: Found Autz-Type WIRELESS
Fri Feb 8 08:55:09 2008 : Debug: +- entering group WIRELESS
Fri Feb 8 08:55:09 2008 : Debug: modsingle[authorize]: calling
wirlss_erebus (rlm_ldap) for request 1114
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: - authorize
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing user
authorization for STUDENTS\kcook
Fri Feb 8 08:55:09 2008 : Debug: radius_xlat: Running registered xlat
function of module mschap for string 'User-Name'
Fri Feb 8 08:55:09 2008 : Debug: expand:
(uid=%{mschap:User-Name}) -> (uid=kcook)
Fri Feb 8 08:55:09 2008 : Debug: expand: ou=Users, dc=clarku,
dc=edu -> ou=Users, dc=clarku, dc=edu
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: performing search in
ou=Users, dc=clarku, dc=edu , with filter (uid=kcook)
Fri Feb 8 08:55:09 2008 : Debug: rlm_ldap: checking if remote access
for STUDENTS\kcook is allowed by clarkuWirelessAccess
Segmentation fault
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 1157658944 (LWP 3794)]
0x00002aaaac516d85 in ldap_authorize (instance=0x4077b30,
request=0x4202a30) at rlm_ldap.c:1319
1319 if (!strncmp(vals[0], "FALSE", 5)) {
(gdb) bt
#0 0x00002aaaac516d85 in ldap_authorize (instance=0x4077b30,
request=0x4202a30) at rlm_ldap.c:1319
#1 0x0000000000411d13 in modcall (component=<value optimized out>,
c=<value optimized out>, request=0x4202a30) at modcall.c:248
#2 0x000000000040ee59 in indexed_modcall (comp=1, idx=<value optimized
out>, request=0x4202a30) at modules.c:446
#3 0x000000000040711b in rad_authenticate (request=0x4202a30) at auth.c:546
#4 0x0000000000418b4b in radius_handle_request (request=0x4202a30,
fun=0x407000 <rad_authenticate>) at event.c:2707
#5 0x0000000000413f78 in request_handler_thread (arg=<value optimized
out>) at threads.c:488
#6 0x0000003da1c062f7 in start_thread () from /lib64/libpthread.so.0
#7 0x0000003da0cce85d in clone () from /lib64/libc.so.6
(gdb) print vals
$1 = (char **) 0xffffffffb00020e0
(gdb) print vals[0]
Cannot access memory at address 0xffffffffb00020e0
(gdb) print inst->access_attr
No symbol "inst" in current context.
(gdb) print instance
$2 = (void *) 0x4077b30
(gdb) print instance->access_attr
Attempt to dereference a generic pointer.
(gdb) print ((ldap_instance *)instance)->access_attr
$3 = 0x4077d90 "clarkuWirelessAccess"
(gdb) print ((ldap_instance *)instance)->default_allow
$4 = 1
(gdb) print msg
$5 = (LDAPMessage *) 0x2aaab0002710
(gdb) print conn->ld
Cannot access memory at address 0x0
(gdb) print conn
$6 = <value optimized out>
Joe Vieira
UNIX Systems Administrator
Clark University - ITS
Alan DeKok wrote:
> Joe Vieira wrote:
>
>> So, i just attached gdb to the running server and ended with this seg
>> fault.
>>
>
> It's likely a side-effect of some other memory issue.
>
> If it's an AMD 64-bit system, then "valgrind" should work.
>
> You can also run the server with more debugging as:
>
> $ radiusd -fxxxx
>
> In which case it won't daemonize itself, but it *will* start multiple
> threads. It looks like the issue is related to threading, if it works
> when '-X' is used.
>
> Alan DeKok.
>
More information about the Freeradius-Users
mailing list