Problems with 1.0.6-2.0.1 connecting to OpenLDAP 2.3.33
I'm running FreeRadius 2.0.1 on OpenBSD 4.2 on sparc64. I've also tried versions 1.0.6 and 1.1.6. I'm using OpenLDAP 2.3.33 with rlm_ldap. It works for the first request, then returns the following: From FreeRadius: Ready to process requests. rad_recv: Access-Request packet from host 127.0.0.1 port 2362, id=66, length=56 User-Name = "zach" User-Password = "*****" NAS-IP-Address = 192.168.2.11 NAS-Port = 1812 +- entering group authorize ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop rlm_realm: No '@' in User-Name = "zach", looking up realm NULL rlm_realm: No such realm "NULL" ++[suffix] returns noop rlm_eap: No EAP-Message, not doing EAP ++[eap] returns noop ++[unix] returns notfound ++[files] returns noop rlm_ldap: - authorize rlm_ldap: performing user authorization for zach WARNING: Deprecated conditional expansion ":-". See "man unlang" for details expand: (uid=%{Stripped-User-Name:-%{User-Name}}) -> (uid=zach) expand: o=zachlowry.net,c=US -> o=zachlowry.net,c=US rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in o=zachlowry.net,c=US, with filter (uid=zach) rlm_ldap: ldap_search() failed: Timed out while waiting for server to respond. Please increase the timeout. rlm_ldap: search failed rlm_ldap: ldap_release_conn: Release Id: 0 ++[ldap] returns fail Invalid user: [zach/*****] (from client localhost port 1812) Found Post-Auth-Type Reject +- entering group REJECT expand: %{User-Name} -> zach attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 2 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 2 Sending Access-Reject of id 66 to 127.0.0.1 port 2362 Waking up in 4.9 seconds. Cleaning up request 2 ID 66 with timestamp +113 Ready to process requests. From OpenLDAP: Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=4 SRCH base="o=zachlowry.net,c=US" scope=2 deref=0 filter="(uid=zach)" Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=4 SRCH attr=radiusNASIpAddress radiusExpiration acctFlags sambaNtPassword sambaLmPassword ntPassword lmPassword radiusCallingStationId radiusCalledStationId radiusSimultaneousUse radiusAuthType radiusCheckItem radiusReplyMessage radiusLoginLATPort radiusPortLimit radiusFramedAppleTalkZone radiusFramedAppleTalkNetwork radiusFramedAppleTalkLink radiusLoginLATGroup radiusLoginLATNode radiusLoginLATService radiusTerminationAction radiusIdleTimeout radiusSessionTimeout radiusClass radiusFramedIPXNetwork radiusCallbackId Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=4 SRCH attr=radiusCallbackNumber radiusLoginTCPPort radiusLoginService radiusLoginIPHost radiusFramedCompression radiusFramedMTU radiusFilterId radiusFramedRouting radiusFramedRoute radiusFramedIPNetmask radiusFramedIPAddress radiusFramedProtocol radiusServiceType radiusReplyItem userPassword Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=5 ABANDON msg=5 I can't find where the ABANDON is sent to the LDAP server. The "increase the timeout" error is found easily enough in rlm_ldap.c, but I can't figure out what timeout to increase. I think there's a deeper issue afoot, however. Thanks, --Zach
Sorry to reply to my own post, just curious if anyone had a chance to take a glance at this. I'm still stumped and starting to suspect that my OpenLDAP is borked somehow, due to the numerous revisions of Freeradius I've attempted now. Thanks again, --Zach On Mar 1, 2008, at 6:18 PM, Zach Lowry wrote:
I'm running FreeRadius 2.0.1 on OpenBSD 4.2 on sparc64. I've also tried versions 1.0.6 and 1.1.6. I'm using OpenLDAP 2.3.33 with rlm_ldap. It works for the first request, then returns the following:
From FreeRadius:
Ready to process requests. rad_recv: Access-Request packet from host 127.0.0.1 port 2362, id=66, length=56 User-Name = "zach" User-Password = "*****" NAS-IP-Address = 192.168.2.11 NAS-Port = 1812 +- entering group authorize ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop rlm_realm: No '@' in User-Name = "zach", looking up realm NULL rlm_realm: No such realm "NULL" ++[suffix] returns noop rlm_eap: No EAP-Message, not doing EAP ++[eap] returns noop ++[unix] returns notfound ++[files] returns noop rlm_ldap: - authorize rlm_ldap: performing user authorization for zach WARNING: Deprecated conditional expansion ":-". See "man unlang" for details expand: (uid=%{Stripped-User-Name:-%{User-Name}}) -> (uid=zach) expand: o=zachlowry.net,c=US -> o=zachlowry.net,c=US rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in o=zachlowry.net,c=US, with filter (uid=zach) rlm_ldap: ldap_search() failed: Timed out while waiting for server to respond. Please increase the timeout. rlm_ldap: search failed rlm_ldap: ldap_release_conn: Release Id: 0 ++[ldap] returns fail Invalid user: [zach/*****] (from client localhost port 1812) Found Post-Auth-Type Reject +- entering group REJECT expand: %{User-Name} -> zach attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 2 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 2 Sending Access-Reject of id 66 to 127.0.0.1 port 2362 Waking up in 4.9 seconds. Cleaning up request 2 ID 66 with timestamp +113 Ready to process requests.
From OpenLDAP:
Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=4 SRCH base="o=zachlowry.net,c=US" scope=2 deref=0 filter="(uid=zach)" Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=4 SRCH attr=radiusNASIpAddress radiusExpiration acctFlags sambaNtPassword sambaLmPassword ntPassword lmPassword radiusCallingStationId radiusCalledStationId radiusSimultaneousUse radiusAuthType radiusCheckItem radiusReplyMessage radiusLoginLATPort radiusPortLimit radiusFramedAppleTalkZone radiusFramedAppleTalkNetwork radiusFramedAppleTalkLink radiusLoginLATGroup radiusLoginLATNode radiusLoginLATService radiusTerminationAction radiusIdleTimeout radiusSessionTimeout radiusClass radiusFramedIPXNetwork radiusCallbackId Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=4 SRCH attr=radiusCallbackNumber radiusLoginTCPPort radiusLoginService radiusLoginIPHost radiusFramedCompression radiusFramedMTU radiusFilterId radiusFramedRouting radiusFramedRoute radiusFramedIPNetmask radiusFramedIPAddress radiusFramedProtocol radiusServiceType radiusReplyItem userPassword Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text= Mar 1 10:25:01 tweedledum slapd[9985]: conn=8483 op=5 ABANDON msg=5
I can't find where the ABANDON is sent to the LDAP server. The "increase the timeout" error is found easily enough in rlm_ldap.c, but I can't figure out what timeout to increase. I think there's a deeper issue afoot, however.
Thanks,
--Zach
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Zach Lowry wrote:
Sorry to reply to my own post, just curious if anyone had a chance to take a glance at this. I'm still stumped and starting to suspect that my OpenLDAP is borked somehow, due to the numerous revisions of Freeradius I've attempted now.
Or maybe the OpenLDAP libraries on your system. Do the command-line ldap tools work? Do other applications using the ldap libraries work? Alan DeKok.
On Mar 4, 2008, at 12:08 AM, Alan DeKok wrote:
Zach Lowry wrote:
Sorry to reply to my own post, just curious if anyone had a chance to take a glance at this. I'm still stumped and starting to suspect that my OpenLDAP is borked somehow, due to the numerous revisions of Freeradius I've attempted now.
Or maybe the OpenLDAP libraries on your system.
Do the command-line ldap tools work?
Yes. ldapadd/search/mod/etc all work fine.
Do other applications using the ldap libraries work?
Yes. I'm also running Heimdal with an LDAP backend on the same system.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Thanks, --Zach
On Mar 4, 2008, at 7:12 AM, Zach Lowry wrote:
On Mar 4, 2008, at 12:08 AM, Alan DeKok wrote:
Zach Lowry wrote:
Sorry to reply to my own post, just curious if anyone had a chance to take a glance at this. I'm still stumped and starting to suspect that my OpenLDAP is borked somehow, due to the numerous revisions of Freeradius I've attempted now.
Or maybe the OpenLDAP libraries on your system.
Do the command-line ldap tools work?
Yes. ldapadd/search/mod/etc all work fine.
Do other applications using the ldap libraries work?
Yes. I'm also running Heimdal with an LDAP backend on the same system.
I think I may have gotten a little bit closer to uncovering my problem. I installed FreeRadius 1.1.7 on a FreeBSD SPARC64 machine, and got some debugging output. I then tried it again on my OpenBSD SPARC64 machine with the debugging turned all the way up: rad_recv: Access-Request packet from host 127.0.0.1:21754, id=176, length=56 User-Name = "zach" User-Password = "*****" NAS-IP-Address = 255.255.255.255 NAS-Port = 1812 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 modcall[authorize]: module "chap" returns noop for request 0 modcall[authorize]: module "mschap" returns noop for request 0 rlm_realm: No '@' in User-Name = "zach", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 0 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 0 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 0 rlm_ldap: - authorize rlm_ldap: performing user authorization for zach radius_xlat: '(uid=zach)' radius_xlat: 'ou=People,o=zachlowry.net,c=US' rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: attempting LDAP reconnection rlm_ldap: (re)connect to ldapi:///, authentication 0 rlm_ldap: bind as cn=SASLProxy,o=zachlowry.net,c=US/***** to ldapi:/// ldap_bind ldap_simple_bind ldap_sasl_bind ldap_send_initial_request ldap_new_connection 1 1 0 ldap_int_open_connection ldap_open_defconn: successful ldap_send_server_request rlm_ldap: waiting for bind result ... ldap_result ld 0x4b926000 msgid 1 ldap_chkResponseList ld 0x4b926000 msgid 1 all 1 ldap_chkResponseList returns ld 0x4b926000 NULL wait4msg ld 0x4b926000 msgid 1 (timeout 171798691840000000 usec) wait4msg continue ld 0x4b926000 msgid 1 all 1 ** ld 0x4b926000 Connections: * host: (null) port: 0 (default) refcnt: 2 status: Connected last used: Wed Mar 5 20:45:00 2008 ** ld 0x4b926000 Outstanding Requests: * msgid 1, origid 1, status InProgress outstanding referrals 0, parent count 0 ** ld 0x4b926000 Response Queue: Empty ldap_chkResponseList ld 0x4b926000 msgid 1 all 1 ldap_chkResponseList returns ld 0x4b926000 NULL ldap_int_select read1msg: ld 0x4b926000 msgid 1 all 1 read1msg: ld 0x4b926000 msgid 1 message type bind new result: res_errno: 0, res_error: <>, res_matched: <> read1msg: ld 0x4b926000 0 new referrals read1msg: mark request completed, ld 0x4b926000 msgid 1 request done: ld 0x4b926000 msgid 1 res_errno: 0, res_error: <>, res_matched: <> ldap_free_request (origid 1, msgid 1) ldap_free_connection 0 1 ldap_free_connection: refcnt 1 ldap_parse_result ldap_msgfree rlm_ldap: Bind was successful rlm_ldap: performing search in ou=People,o=zachlowry.net,c=US, with filter (uid=zach) ldap_search put_filter: "(uid=zach)" put_filter: simple put_simple_filter: "uid=zach" ldap_build_search_req ATTRS: radiusNASIpAddress radiusExpiration acctFlags ntPassword lmPassword radiusCallingStationId radiusCalledStationId radiusSimultaneousUse radiusAuthType radiusCheckItem radiusReplyMessage radiusLoginLATPort radiusPortLimit radiusFramedAppleTalkZone radiusFramedAppleTalkNetwork radiusFramedAppleTalkLink radiusLoginLATGroup radiusLoginLATNode radiusLoginLATService radiusTerminationAction radiusIdleTimeout radiusSessionTimeout radiusClass radiusFramedIPXNetwork radiusCallbackId radiusCallbackNumber radiusLoginTCPPort radiusLoginService radiusLoginIPHost radiusFramedCompression radiusFramedMTU radiusFilterId radiusFramedRouting radiusFramedRoute radiusFramedIPNetmask radiusFramedIPAddress radiusFramedProtocol radiusServiceType radiusReplyItem userPassword uid ldap_send_initial_request ldap_send_server_request ldap_result ld 0x4b926000 msgid 2 ldap_chkResponseList ld 0x4b926000 msgid 2 all 1 ldap_chkResponseList returns ld 0x4b926000 NULL wait4msg ld 0x4b926000 msgid 2 (timeout 171798691840000000 usec) wait4msg continue ld 0x4b926000 msgid 2 all 1 ** ld 0x4b926000 Connections: * host: (null) port: 0 (default) refcnt: 2 status: Connected last used: Wed Mar 5 20:45:01 2008 ** ld 0x4b926000 Outstanding Requests: * msgid 2, origid 2, status InProgress outstanding referrals 0, parent count 0 ** ld 0x4b926000 Response Queue: Empty ldap_chkResponseList ld 0x4b926000 msgid 2 all 1 ldap_chkResponseList returns ld 0x4b926000 NULL ldap_int_select ldap_abandon 2 ldap_abandon_ext 2 do_abandon origid 2, msgid 2 ldap_msgdelete ldap_free_connection 0 1 ldap_free_connection: refcnt 1 ldap_free_request (origid 2, msgid 2) rlm_ldap: ldap_search() failed: Timed out while waiting for server to respond. Please increase the timeout. ldap_msgfree rlm_ldap: search failed rlm_ldap: ldap_release_conn: Release Id: 0 modcall[authorize]: module "ldap" returns fail for request 0 modcall: leaving group authorize (returns fail) for request 0 There was no response configured: rejecting request 0 Server rejecting request 0. Finished request 0 The really interesting output comes from the FreeBSD box, though: Starting - reading configuration files ... reread_config: reading radiusd.conf Config: including file: /usr/local/etc/raddb/proxy.conf Config: including file: /usr/local/etc/raddb/clients.conf Config: including file: /usr/local/etc/raddb/snmp.conf Config: including file: /usr/local/etc/raddb/eap.conf Config: including file: /usr/local/etc/raddb/sql.conf main: prefix = "/usr/local" main: localstatedir = "/var" main: logdir = "/var/log" main: libdir = "/usr/local/lib" main: radacctdir = "/var/log/radacct" main: hostname_lookups = no main: max_request_time = 30 main: cleanup_delay = 5 main: max_requests = 1024 main: delete_blocked_requests = 0 main: port = 0 main: allow_core_dumps = no main: log_stripped_names = no main: log_file = "/var/log/radius.log" main: log_auth = no main: log_auth_badpass = no main: log_auth_goodpass = no main: pidfile = "/var/run/radiusd/radiusd.pid" main: user = "(null)" main: group = "(null)" main: usercollide = no main: lower_user = "no" main: lower_pass = "no" main: nospace_user = "no" main: nospace_pass = "no" main: checkrad = "/usr/local/sbin/checkrad" main: proxy_requests = yes proxy: retry_delay = 5 proxy: retry_count = 3 proxy: synchronous = no proxy: default_fallback = yes proxy: dead_time = 120 proxy: post_proxy_authorize = no proxy: wake_all_if_all_dead = no security: max_attributes = 200 security: reject_delay = 1 security: status_server = no main: debug_level = 0 read_config_files: reading dictionary read_config_files: reading naslist Using deprecated naslist file. Support for this will go away soon. read_config_files: reading clients read_config_files: reading realms radiusd: entering modules setup Module: Library search path is /usr/local/lib Module: Loaded exec exec: wait = yes exec: program = "(null)" exec: input_pairs = "request" exec: output_pairs = "(null)" exec: packet_type = "(null)" rlm_exec: Wait=yes but no output defined. Did you mean output=none? Module: Instantiated exec (exec) Module: Loaded expr Module: Instantiated expr (expr) Module: Loaded PAP pap: encryption_scheme = "crypt" pap: auto_header = yes Module: Instantiated pap (pap) Module: Loaded CHAP Module: Instantiated chap (chap) Module: Loaded MS-CHAP mschap: use_mppe = yes mschap: require_encryption = no mschap: require_strong = no mschap: with_ntdomain_hack = no mschap: passwd = "(null)" mschap: ntlm_auth = "(null)" Module: Instantiated mschap (mschap) Module: Loaded System unix: cache = no unix: passwd = "(null)" unix: shadow = "(null)" unix: group = "(null)" unix: radwtmp = "/var/log/radwtmp" unix: usegroup = no unix: cache_reload = 600 Module: Instantiated unix (unix) Module: Loaded eap eap: default_eap_type = "md5" eap: timer_expire = 60 eap: ignore_unknown_eap_types = no eap: cisco_accounting_username_bug = no rlm_eap: Loaded and initialized type md5 rlm_eap: Loaded and initialized type leap gtc: challenge = "Password: " gtc: auth_type = "PAP" rlm_eap: Loaded and initialized type gtc mschapv2: with_ntdomain_hack = no rlm_eap: Loaded and initialized type mschapv2 Module: Instantiated eap (eap) Module: Loaded preprocess preprocess: huntgroups = "/usr/local/etc/raddb/huntgroups" preprocess: hints = "/usr/local/etc/raddb/hints" preprocess: with_ascend_hack = no preprocess: ascend_channels_per_line = 23 preprocess: with_ntdomain_hack = no preprocess: with_specialix_jetstream_hack = no preprocess: with_cisco_vsa_hack = no preprocess: with_alvarion_vsa_hack = no Module: Instantiated preprocess (preprocess) Module: Loaded realm realm: format = "suffix" realm: delimiter = "@" realm: ignore_default = no realm: ignore_null = no Module: Instantiated realm (suffix) Module: Loaded files files: usersfile = "/usr/local/etc/raddb/users" files: acctusersfile = "/usr/local/etc/raddb/acct_users" files: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users" files: compat = "no" Module: Instantiated files (files) Module: Loaded LDAP ldap: server = "ldap://192.168.2.9/" ldap: port = 389 ldap: net_timeout = 1 ldap: timeout = 1 ldap: timelimit = 1 ldap: identity = "cn=SASLProxy,o=zachlowry.net,c=US" ldap: tls_mode = no ldap: start_tls = no ldap: tls_cacertfile = "/etc/ssl/cacert.pem" ldap: tls_cacertdir = "(null)" ldap: tls_certfile = "(null)" ldap: tls_keyfile = "(null)" ldap: tls_randfile = "(null)" ldap: tls_require_cert = "allow" ldap: password = "*****" ldap: basedn = "o=zachlowry.net,c=US" ldap: filter = "(uid=%{Stripped-User-Name:-%{User-Name}})" ldap: base_filter = "(objectclass=radiusprofile)" ldap: default_profile = "(null)" ldap: profile_attribute = "(null)" ldap: password_header = "(null)" ldap: password_attribute = "userPassword" ldap: access_attr = "cn" ldap: groupname_attribute = "cn" ldap: groupmembership_filter = "(|(&(objectClass=GroupOfNames) (member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames) (uniquemember=%{Ldap-UserDn})))" ldap: groupmembership_attribute = "(null)" ldap: dictionary_mapping = "/usr/local/etc/raddb/ldap.attrmap" ldap: ldap_debug = -1 ldap: ldap_connections_number = 1 ldap: compare_check_items = no ldap: access_attr_used_for_allow = yes ldap: do_xlat = yes ldap: set_auth_type = no rlm_ldap: Registering ldap_groupcmp for Ldap-Group rlm_ldap: Registering ldap_xlat with xlat_name ldap rlm_ldap: reading ldap<->radius mappings from file /usr/local/etc/ raddb/ldap.attrmap rlm_ldap: LDAP radiusCheckItem mapped to RADIUS $GENERIC$ rlm_ldap: LDAP radiusReplyItem mapped to RADIUS $GENERIC$ rlm_ldap: LDAP radiusAuthType mapped to RADIUS Auth-Type rlm_ldap: LDAP radiusSimultaneousUse mapped to RADIUS Simultaneous-Use rlm_ldap: LDAP radiusCalledStationId mapped to RADIUS Called-Station-Id rlm_ldap: LDAP radiusCallingStationId mapped to RADIUS Calling- Station-Id rlm_ldap: LDAP lmPassword mapped to RADIUS LM-Password rlm_ldap: LDAP ntPassword mapped to RADIUS NT-Password rlm_ldap: LDAP acctFlags mapped to RADIUS SMB-Account-CTRL-TEXT rlm_ldap: LDAP radiusExpiration mapped to RADIUS Expiration rlm_ldap: LDAP radiusNASIpAddress mapped to RADIUS NAS-IP-Address rlm_ldap: LDAP radiusServiceType mapped to RADIUS Service-Type rlm_ldap: LDAP radiusFramedProtocol mapped to RADIUS Framed-Protocol rlm_ldap: LDAP radiusFramedIPAddress mapped to RADIUS Framed-IP-Address rlm_ldap: LDAP radiusFramedIPNetmask mapped to RADIUS Framed-IP-Netmask rlm_ldap: LDAP radiusFramedRoute mapped to RADIUS Framed-Route rlm_ldap: LDAP radiusFramedRouting mapped to RADIUS Framed-Routing rlm_ldap: LDAP radiusFilterId mapped to RADIUS Filter-Id rlm_ldap: LDAP radiusFramedMTU mapped to RADIUS Framed-MTU rlm_ldap: LDAP radiusFramedCompression mapped to RADIUS Framed- Compression rlm_ldap: LDAP radiusLoginIPHost mapped to RADIUS Login-IP-Host rlm_ldap: LDAP radiusLoginService mapped to RADIUS Login-Service rlm_ldap: LDAP radiusLoginTCPPort mapped to RADIUS Login-TCP-Port rlm_ldap: LDAP radiusCallbackNumber mapped to RADIUS Callback-Number rlm_ldap: LDAP radiusCallbackId mapped to RADIUS Callback-Id rlm_ldap: LDAP radiusFramedIPXNetwork mapped to RADIUS Framed-IPX- Network rlm_ldap: LDAP radiusClass mapped to RADIUS Class rlm_ldap: LDAP radiusSessionTimeout mapped to RADIUS Session-Timeout rlm_ldap: LDAP radiusIdleTimeout mapped to RADIUS Idle-Timeout rlm_ldap: LDAP radiusTerminationAction mapped to RADIUS Termination- Action rlm_ldap: LDAP radiusLoginLATService mapped to RADIUS Login-LAT-Service rlm_ldap: LDAP radiusLoginLATNode mapped to RADIUS Login-LAT-Node rlm_ldap: LDAP radiusLoginLATGroup mapped to RADIUS Login-LAT-Group rlm_ldap: LDAP radiusFramedAppleTalkLink mapped to RADIUS Framed- AppleTalk-Link rlm_ldap: LDAP radiusFramedAppleTalkNetwork mapped to RADIUS Framed- AppleTalk-Network rlm_ldap: LDAP radiusFramedAppleTalkZone mapped to RADIUS Framed- AppleTalk-Zone rlm_ldap: LDAP radiusPortLimit mapped to RADIUS Port-Limit rlm_ldap: LDAP radiusLoginLATPort mapped to RADIUS Login-LAT-Port rlm_ldap: LDAP radiusReplyMessage mapped to RADIUS Reply-Message conns: 0x2cadc0 Module: Instantiated ldap (ldap) Module: Loaded Acct-Unique-Session-Id acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Module: Instantiated acct_unique (acct_unique) Module: Loaded detail detail: detailfile = "/var/log/radacct/%{Client-IP-Address}/detail-% Y%m%d" detail: detailperm = 384 detail: dirperm = 493 detail: locking = no Module: Instantiated detail (detail) Module: Loaded radutmp radutmp: filename = "/var/log/radutmp" radutmp: username = "%{User-Name}" radutmp: case_sensitive = yes radutmp: check_with_nas = yes radutmp: perm = 384 radutmp: callerid = yes Module: Instantiated radutmp (radutmp) Listening on authentication *:1812 Listening on accounting *:1813 Ready to process requests. rad_recv: Access-Request packet from host 127.0.0.1:53532, id=41, length=56 User-Name = "zach" User-Password = "*****" NAS-IP-Address = 255.255.255.255 NAS-Port = 1812 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 modcall[authorize]: module "chap" returns noop for request 0 modcall[authorize]: module "mschap" returns noop for request 0 rlm_realm: No '@' in User-Name = "zach", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 0 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 0 users: Matched entry DEFAULT at line 153 modcall[authorize]: module "files" returns ok for request 0 rlm_ldap: - authorize rlm_ldap: performing user authorization for zach radius_xlat: '(uid=zach)' radius_xlat: 'o=zachlowry.net,c=US' rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: attempting LDAP reconnection rlm_ldap: (re)connect to ldap://192.168.2.9/, authentication 0 rlm_ldap: setting TLS CACert File to /etc/ssl/cacert.pem rlm_ldap: bind as cn=SASLProxy,o=zachlowry.net,c=US/***** to ldap:// 192.168.2.9/ ldap_bind ldap_simple_bind ldap_sasl_bind ldap_send_initial_request ldap_new_connection 1 1 0 ldap_int_open_connection ldap_connect_to_host: TCP 192.168.2.9:389 ldap_new_socket: 7 ldap_prepare_socket: 7 ldap_connect_to_host: Trying 192.168.2.9:389 ldap_connect_timeout: fd: 7 tm: 4294967296 async: 0 ^^^^^^^^^^ What is this doing here? ldap_ndelay_on: 7 ldap_connect_timeout: timed out ldap_close_socket: 7 ldap_err2string rlm_ldap: cn=SASLProxy,o=zachlowry.net,c=US bind to ldap:// 192.168.2.9/ failed: Can't contact LDAP server rlm_ldap: (re)connection attempt failed rlm_ldap: search failed rlm_ldap: ldap_release_conn: Release Id: 0 modcall[authorize]: module "ldap" returns fail for request 0 modcall: leaving group authorize (returns fail) for request 0 Finished request 0 Going to the next request --- Walking the entire request list --- Could this be a 64-bit portability issue in rlm_ldap? Thanks, --Zach
Zach Lowry wrote:
I think I may have gotten a little bit closer to uncovering my problem. I installed FreeRadius 1.1.7 on a FreeBSD SPARC64 machine, and got some debugging output. I then tried it again on my OpenBSD SPARC64 machine with the debugging turned all the way up: ... ldap_connect_timeout: fd: 7 tm: 4294967296 async: 0 ^^^^^^^^^^ What is this doing here?
That looks like "now", in time_t format. It may have been taken from the wrong thing, tho...
Could this be a 64-bit portability issue in rlm_ldap?
Likely. See "net_timeout" in the CONF_PARSER module_config structure. It's parsing integers into a "tv_sec", which is type time_t. The data should really be parsed into an "int" type, and that later assigned to a tv_sec. Alan DeKok.
On Mar 6, 2008, at 12:16 AM, Alan DeKok wrote:
Zach Lowry wrote:
I think I may have gotten a little bit closer to uncovering my problem. I installed FreeRadius 1.1.7 on a FreeBSD SPARC64 machine, and got some debugging output. I then tried it again on my OpenBSD SPARC64 machine with the debugging turned all the way up: ... ldap_connect_timeout: fd: 7 tm: 4294967296 async: 0 ^^^^^^^^^^ What is this doing here?
That looks like "now", in time_t format. It may have been taken from the wrong thing, tho...
It's actually 2^32. Since I can accurately set the time to -1 or 0, I believe that the bug is coming from one library writing a 64-bit value and another reading it as a 32-bit integer.
Could this be a 64-bit portability issue in rlm_ldap?
Likely. See "net_timeout" in the CONF_PARSER module_config structure. It's parsing integers into a "tv_sec", which is type time_t. The data should really be parsed into an "int" type, and that later assigned to a tv_sec.
OK, hardcoding values fixes it. Like this: if (ldap_set_option(ld, LDAP_OPT_NETWORK_TIMEOUT, 10) != LDAP_OPT_SUCCESS) { radlog(L_ERR, "rlm_ldap: Could not set LDAP_OPT_NETWORK_TIMEOUT %ld.%ld", inst->net_timeout.tv_sec, inst-
net_timeou t.tv_usec); } if (ldap_set_option(ld, LDAP_OPT_TIMELIMIT, 10) != LDAP_OPT_SUCCESS) { radlog(L_ERR, "rlm_ldap: Could not set LDAP_OPT_TIMELIMIT %d", inst->timelimit); }
I'll work on a better long-term solution.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/ users.html
Please try the attached patch. If it works, I'll commit it to CVS. Alan DeKok.
On Mar 6, 2008, at 12:16 AM, Alan DeKok wrote:
Could this be a 64-bit portability issue in rlm_ldap?
Likely. See "net_timeout" in the CONF_PARSER module_config structure. It's parsing integers into a "tv_sec", which is type time_t. The data should really be parsed into an "int" type, and that later assigned to a tv_sec.
Problems. On OpenBSD, a timeval is like this: struct timeval { long tv_sec; /* seconds */ long tv_usec; /* and microseconds */ }; Longs are 8 bytes, so it's writing the value of the configuration parameter into the first 4 bytes of the value. I modified CONF_PARSER like this: {"net_timeout", PW_TYPE_INTEGER, offsetof (ldap_instance,net_timeout.tv_sec)+4, NULL, "10"}, /* wait forever for search results */ {"timeout", PW_TYPE_INTEGER, offsetof (ldap_instance,timeout.tv_sec)+4, NULL, "20"}, /* allow server unlimited time for search (server-side limit) */ An ugly hack, for sure. But it gets the correct values into the struct. Then we have the next problem: if (ldap_set_option(ld, LDAP_OPT_NETWORK_TIMEOUT, (void *) & (inst->net_timeout)) != LDAP_OPT_SUCCESS) { radlog(L_ERR, "rlm_ldap: Could not set LDAP_OPT_NETWORK_TIMEOUT %d.%ld", inst->net_timeout.tv_sec, inst-
net_timeout .tv_usec); }
I added this right below the above lines: struct timeval net_timeout_value = {0, 0}; ldap_get_option(ld, LDAP_OPT_NETWORK_TIMEOUT, &net_timeout_value); radlog(L_ERR, "ZBL: LDAP_OPT_NETWORK_TIMEOUT %ld.%ld", net_timeout_value.tv_sec, net_timeout_value.tv_usec); and got this output: ZBL: LDAP_OPT_NETWORK_TIMEOUT 1077901232.0 It certainly seems like something fishy is going on here, any more ideas? Thanks, --Zach
On Mar 9, 2008, at 9:14 PM, Zach Lowry wrote:
and got this output:
ZBL: LDAP_OPT_NETWORK_TIMEOUT 1077901232.0
It certainly seems like something fishy is going on here, any more ideas?
Argh. This was caused by my own error. Things look to be working better now. What would the best way be to handle OpenBSD's non- standard timeval struct? Thanks, --Zach
Zach Lowry wrote:
Argh. This was caused by my own error. Things look to be working better now. What would the best way be to handle OpenBSD's non-standard timeval struct?
There is no standard timeval structure. It's always machine dependent. The problem here is that rlm_ldap parses "int"'s into a "tv_sec". That's wrong, and needs to be fixed. It needs to parse "int"s into an "int", and then later assign them to a tv_sec. Do you have a working patch? Alan DeKok.
On Mar 10, 2008, at 12:31 AM, Alan DeKok wrote:
Zach Lowry wrote:
Argh. This was caused by my own error. Things look to be working better now. What would the best way be to handle OpenBSD's non-standard timeval struct?
There is no standard timeval structure. It's always machine dependent.
The problem here is that rlm_ldap parses "int"'s into a "tv_sec". That's wrong, and needs to be fixed. It needs to parse "int"s into an "int", and then later assign them to a tv_sec.
Do you have a working patch?
Alan DeKok.
Ah, I see. The patch makes more sense than what I did, and works flawlessly. Thanks so much for your help! --Zach
participants (2)
-
Alan DeKok -
Zach Lowry