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.