Startup problem with ldap
Hi, I'm trying to run a freeradius 1.1.7 with ldap as authorize and authenticate backend and I'm having trouble with freeradius startup. If the server is started with radiusd -X or radiusd -s all is fine and the requests get answered correctly. If the server is started with radiusd -y it doesn't statup correctly. >From the radiusd.log file I notice that the line Fri Nov 2 09:37:54 2007 : Info: Ready to process requests. is missing. If I comment the ldap section in authorize and authenticate the server startup correcly also with -y startup flag. I've tried some debugging and I found that the server will fork correctly, the parent exit but the child never come alive as the line "Here before setsid" dosn't compare in the logfile. I've also tried to start gdb on the running process to see where the process is and the results are reported at the end of the message. Here there are the modified section of radiusd.c, the radiusd.log and the output of the gdb session. :::::::::: radiusd.c: :::::::::: ..... /* * Disconnect from session */ if (debug_flag == 0 && dont_fork == FALSE) { pid = fork(); if(pid < 0) { radlog(L_ERR|L_CONS, "Couldn't fork"); exit(1); } /* * The parent exits, so the child can run in the background. */ if(pid > 0) { radlog(L_ERR, "Parent Exit"); exit(0); } radlog(L_ERR, "Here before setsid"); #ifdef HAVE_SETSID setsid(); #endif ...... :::::::::::: radiusd.log: :::::::::::: Fri Nov 2 09:56:33 2007 : Info: rlm_exec: Wait=yes but no output defined. Did you mean output=none? Fri Nov 2 09:56:33 2007 : Info: rlm_sql (sql): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked Fri Nov 2 09:56:33 2007 : Info: rlm_sql (sql): Attempting to connect to radius@localhost:/radius Fri Nov 2 09:56:33 2007 : Error: Parent Exit ::::::::: gdb ::::::::: [root@stargate main]# gdb .libs/radiusd 20867 GNU gdb Red Hat Linux (6.6-16.fc7rh) Copyright (C) 2006 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or distribute copies of it under certain conditions. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. This GDB was configured as "i386-redhat-linux-gnu"... Using host libthread_db library "/lib/libthread_db.so.1". Attaching to program: /usr/src/redhat/BUILD/freeradius-1.1.7/src/main/.libs/radiusd, process 20867 Loaded symbols for /usr/src/redhat/BUILD/freeradius-1.1.7/src/main/.libs/radiusd Reading symbols from /lib/libnsl.so.1...done. Loaded symbols for /lib/libnsl.so.1 Reading symbols from /lib/libresolv.so.2...done. Loaded symbols for /lib/libresolv.so.2 Reading symbols from /lib/libpthread.so.0...done. [Thread debugging using libthread_db enabled] [New Thread -1209166144 (LWP 20867)] Loaded symbols for /lib/libpthread.so.0 Reading symbols from /usr/lib/libradius-1.1.7.so...done. Loaded symbols for /usr/lib/libradius-1.1.7.so Reading symbols from /lib/libcrypt.so.1...done. Loaded symbols for /lib/libcrypt.so.1 Reading symbols from /usr/lib/libsnmp.so.15...done. Loaded symbols for /usr/lib/libsnmp.so.15 Reading symbols from /usr/lib/libltdl.so.3...done. Loaded symbols for /usr/lib/libltdl.so.3 Reading symbols from /lib/libdl.so.2...done. Loaded symbols for /lib/libdl.so.2 Reading symbols from /lib/libssl.so.6...done. Loaded symbols for /lib/libssl.so.6 Reading symbols from /lib/libcrypto.so.6...done. Loaded symbols for /lib/libcrypto.so.6 Reading symbols from /lib/libc.so.6...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /lib/ld-linux.so.2...done. Loaded symbols for /lib/ld-linux.so.2 Reading symbols from /usr/lib/libgssapi_krb5.so.2...done. Loaded symbols for /usr/lib/libgssapi_krb5.so.2 Reading symbols from /usr/lib/libkrb5.so.3...done. Loaded symbols for /usr/lib/libkrb5.so.3 Reading symbols from /lib/libcom_err.so.2...done. Loaded symbols for /lib/libcom_err.so.2 Reading symbols from /usr/lib/libk5crypto.so.3...done. Loaded symbols for /usr/lib/libk5crypto.so.3 Reading symbols from /lib/libz.so.1...done. Loaded symbols for /lib/libz.so.1 Reading symbols from /usr/lib/libkrb5support.so.0...done. Loaded symbols for /usr/lib/libkrb5support.so.0 Reading symbols from /lib/libkeyutils.so.1...done. Loaded symbols for /lib/libkeyutils.so.1 Reading symbols from /lib/libnss_files.so.2...done. Loaded symbols for /lib/libnss_files.so.2 Reading symbols from /usr/lib/libnss_ldap.so.2...done. Loaded symbols for /usr/lib/libnss_ldap.so.2 Reading symbols from /usr/lib/libldap-2.3.so.0...done. Loaded symbols for /usr/lib/libldap-2.3.so.0 Reading symbols from /usr/lib/liblber-2.3.so.0...done. Loaded symbols for /usr/lib/liblber-2.3.so.0 Reading symbols from /usr/lib/libsasl2.so.2...done. Loaded symbols for /usr/lib/libsasl2.so.2 Reading symbols from /usr/lib/rlm_exec.so...done. Loaded symbols for /usr/lib/rlm_exec.so Reading symbols from /usr/lib/rlm_expr.so...done. Loaded symbols for /usr/lib/rlm_expr.so Reading symbols from /usr/lib/rlm_chap.so...done. Loaded symbols for /usr/lib/rlm_chap.so Reading symbols from /usr/lib/rlm_mschap.so...done. Loaded symbols for /usr/lib/rlm_mschap.so Reading symbols from /usr/lib/rlm_ldap.so...done. Loaded symbols for /usr/lib/rlm_ldap.so Reading symbols from /usr/lib/libldap_r-2.3.so.0...done. Loaded symbols for /usr/lib/libldap_r-2.3.so.0 Reading symbols from /usr/lib/rlm_eap.so...done. Loaded symbols for /usr/lib/rlm_eap.so Reading symbols from /usr/lib/libeap-1.1.7.so...done. Loaded symbols for /usr/lib/libeap-1.1.7.so Reading symbols from /usr/lib/rlm_eap_md5.so...done. Loaded symbols for /usr/lib/rlm_eap_md5.so Reading symbols from /usr/lib/rlm_eap_leap.so...done. Loaded symbols for /usr/lib/rlm_eap_leap.so Reading symbols from /usr/lib/rlm_eap_gtc.so...done. Loaded symbols for /usr/lib/rlm_eap_gtc.so Reading symbols from /usr/lib/rlm_eap_mschapv2.so...done. Loaded symbols for /usr/lib/rlm_eap_mschapv2.so Reading symbols from /usr/lib/rlm_preprocess.so...done. Loaded symbols for /usr/lib/rlm_preprocess.so Reading symbols from /usr/lib/rlm_detail.so...done. Loaded symbols for /usr/lib/rlm_detail.so Reading symbols from /usr/lib/rlm_realm.so...done. Loaded symbols for /usr/lib/rlm_realm.so Reading symbols from /usr/lib/rlm_files.so...done. Loaded symbols for /usr/lib/rlm_files.so Reading symbols from /usr/lib/rlm_acct_unique.so...done. Loaded symbols for /usr/lib/rlm_acct_unique.so Reading symbols from /usr/lib/rlm_radutmp.so...done. Loaded symbols for /usr/lib/rlm_radutmp.so Reading symbols from /usr/lib/rlm_sql.so...done. Loaded symbols for /usr/lib/rlm_sql.so Reading symbols from /usr/lib/rlm_sql_postgresql.so...done. Loaded symbols for /usr/lib/rlm_sql_postgresql.so Reading symbols from /usr/lib/libpq.so.5...done. Loaded symbols for /usr/lib/libpq.so.5 0x0012d402 in __kernel_vsyscall () (gdb) backtrace #0 0x0012d402 in __kernel_vsyscall () #1 0x00166a0e in __lll_mutex_lock_wait () from /lib/libpthread.so.0 #2 0x00162883 in _L_mutex_lock_79 () from /lib/libpthread.so.0 #3 0x001623ad in pthread_mutex_lock () from /lib/libpthread.so.0 #4 0x00704e6d in ldap_pvt_thread_mutex_lock () from /usr/lib/libldap_r-2.3.so.0 #5 0x0070f79b in ldap_ld_free () from /usr/lib/libldap_r-2.3.so.0 #6 0x00663dd7 in ?? () from /usr/lib/libnss_ldap.so.2 #7 0x00667504 in ?? () from /usr/lib/libnss_ldap.so.2 #8 0x004892f2 in fork () from /lib/libc.so.6 #9 0x001693a4 in fork () from /lib/libpthread.so.0 #10 0xb7f017b1 in main (argc=2, argv=0xbffe0294) at radiusd.c:1006 Any help apprecieated. Thanks Massimo Meregalli
Massimo Meregalli wrote:
If the server is started with radiusd -X or radiusd -s all is fine and the requests get answered correctly.
Because it doesn't change uid's.
If the server is started with radiusd -y it doesn't statup correctly.
You have likely edited the "user=" and/or "group=" lines in radiusd.conf to set it to run as a non-root user. You have then made the configuration files so that the non-root user doesn't have permission to read them. As root, do "su user", to the user you have configured. Then run "radiusd -X", and you will likely see more output as to what's going wrong. Alan DeKok.
The server is configured to run as radiusd/radiusd and the configuration directory (/etc/raddb) as well as the log directory (/var/log/radiusd) are owned by radiusd with rwx permission for the owner, as all the files included in these directory. I've tried to su - radiusd an then launch the server but I got the same result as before, if the server tries to put itself into backgroud than the child never became ready to process requests. What seems to be strange is that if the LDAP module is commented out from the configuration file then the server is working fine (with an entry from the users file). I've also tried to change the ldap module (rlm_ldap) with the one of the version 1.1.3 (As I've red from the mailing list) with no luck. The configuration I'm testing came from an installation of freeradius 1.1.3 that works fine. Thanks Massimo Meregalli On Fri, 2007-11-02 at 14:19 +0100, Alan DeKok wrote:
Massimo Meregalli wrote:
If the server is started with radiusd -X or radiusd -s all is fine and the requests get answered correctly.
Because it doesn't change uid's.
If the server is started with radiusd -y it doesn't statup correctly.
You have likely edited the "user=" and/or "group=" lines in radiusd.conf to set it to run as a non-root user. You have then made the configuration files so that the non-root user doesn't have permission to read them.
As root, do "su user", to the user you have configured. Then run "radiusd -X", and you will likely see more output as to what's going wrong.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Hi, I made some more tests on this topic and I've found the following: 1) I get the same problem with the fresh configuration files as installed by freeradius 1.1.7. This time I'd expect the server say it can't contact "ldap.your.domain" instead it will stop like when started with my configuration file. The ps command say the server is stopped in the "futex_wait" before generating threads (the ps -eLf command report only one thread). 2) The problem starts only when the ldap module is activated, no matter if the module is configured in authorize or in authentication section. 3) I've tried to start the server with uid = gid = root (to prevent uid change) but I'got the same results. 4) Doing su - radiusd ; radiusd -X doesn't produce output differences compared to when the server i started by root, all the things is working fine. Regards, Massimo Meregalli On Sat, 2007-11-03 at 14:37 +0100, Massimo Meregalli wrote:
The server is configured to run as radiusd/radiusd and the configuration directory (/etc/raddb) as well as the log directory (/var/log/radiusd) are owned by radiusd with rwx permission for the owner, as all the files included in these directory.
I've tried to su - radiusd an then launch the server but I got the same result as before, if the server tries to put itself into backgroud than the child never became ready to process requests.
What seems to be strange is that if the LDAP module is commented out from the configuration file then the server is working fine (with an entry from the users file).
I've also tried to change the ldap module (rlm_ldap) with the one of the version 1.1.3 (As I've red from the mailing list) with no luck.
The configuration I'm testing came from an installation of freeradius 1.1.3 that works fine.
Thanks
Massimo Meregalli
On Fri, 2007-11-02 at 14:19 +0100, Alan DeKok wrote:
Massimo Meregalli wrote:
If the server is started with radiusd -X or radiusd -s all is fine and the requests get answered correctly.
Because it doesn't change uid's.
If the server is started with radiusd -y it doesn't statup correctly.
You have likely edited the "user=" and/or "group=" lines in radiusd.conf to set it to run as a non-root user. You have then made the configuration files so that the non-root user doesn't have permission to read them.
As root, do "su user", to the user you have configured. Then run "radiusd -X", and you will likely see more output as to what's going wrong.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Massimo Meregalli wrote:
1) I get the same problem with the fresh configuration files as installed by freeradius 1.1.7. This time I'd expect the server say it can't contact "ldap.your.domain" instead it will stop like when started with my configuration file. The ps command say the server is stopped in the "futex_wait" before generating threads (the ps -eLf command report only one thread).
Can you attach to the process with gdb, and print the output of "bt"? That would help figure out where the problem lies.
2) The problem starts only when the ldap module is activated, no matter if the module is configured in authorize or in authentication section.
3) I've tried to start the server with uid = gid = root (to prevent uid change) but I'got the same results.
Ok... so it's likely not a permissions issue.
4) Doing su - radiusd ; radiusd -X doesn't produce output differences compared to when the server i started by root, all the things is working fine.
Probably because it's in single-threaded mode. What happens when you start it as root with "radiusd -xxf" ? Alan DeKok.
Ok, On Tue, 2007-11-06 at 00:30 +0100, Alan DeKok wrote:
Massimo Meregalli wrote: ... Can you attach to the process with gdb, and print the output of "bt"? That would help figure out where the problem lies.
The following is the backtrace produced when I attach the debugger to the radiusd process: (gdb) backtrace #0 0x0012d402 in __kernel_vsyscall () #1 0x00166a0e in __lll_mutex_lock_wait () from /lib/libpthread.so.0 #2 0x00162883 in _L_mutex_lock_79 () from /lib/libpthread.so.0 #3 0x001623ad in pthread_mutex_lock () from /lib/libpthread.so.0 #4 0x00704e6d in ldap_pvt_thread_mutex_lock () from /usr/lib/libldap_r-2.3.so.0 #5 0x0070f79b in ldap_ld_free () from /usr/lib/libldap_r-2.3.so.0 #6 0x00663dd7 in ?? () from /usr/lib/libnss_ldap.so.2 #7 0x00667504 in ?? () from /usr/lib/libnss_ldap.so.2 #8 0x004892f2 in fork () from /lib/libc.so.6 #9 0x001693a4 in fork () from /lib/libpthread.so.0 #10 0xb7f017b1 in main (argc=2, argv=0xbffe0294) at radiusd.c:1006 ...
Probably because it's in single-threaded mode. What happens when you start it as root with "radiusd -xxf" ?
The following is the output produced with radiusd -xxf. Launched this way the server work fine but the server doesn't fork and, from the tests performed, the problem seems to be related to the fork/thread interaction. [root@stargate raddb]# radiusd -xxf Starting - reading configuration files ... reread_config: reading radiusd.conf Config: including file: /etc/raddb/.listen.conf Config: including file: /etc/raddb/proxy.conf Config: including file: /etc/raddb/clients.conf Config: including file: /etc/raddb/snmp.conf Config: including file: /etc/raddb/eap.conf Config: including file: /etc/raddb/postgresql.conf main: prefix = "/usr" main: localstatedir = "/var" main: logdir = "/var/log/radius" main: libdir = "/usr/lib" main: radacctdir = "/var/log/radius/radacct" main: hostname_lookups = no main: snmp = yes main: max_request_time = 30 main: cleanup_delay = 5 main: max_requests = 1024 main: delete_blocked_requests = 0 main: port = 1812 main: allow_core_dumps = no main: log_stripped_names = no main: log_file = "/var/log/radius/radius.log" main: log_auth = yes main: log_auth_badpass = no main: log_auth_goodpass = no main: pidfile = "/var/run/radiusd/radiusd.pid" main: user = "radiusd" main: group = "radiusd" main: usercollide = no main: lower_user = "no" main: lower_pass = "no" main: nospace_user = "no" main: nospace_pass = "no" main: checkrad = "/usr/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 read_config_files: reading clients read_config_files: reading realms listen: ipaddr = 192.168.0.10 IP address [192.168.0.10] listen: port = 1812 listen: type = "auth" listen: ipaddr = 192.168.0.10 IP address [192.168.0.10] listen: port = 1813 listen: type = "acct" radiusd: entering modules setup Module: Library search path is /usr/lib Module: Loaded expr Module: Instantiated expr (expr) Module: Loaded CHAP Module: Instantiated chap (chap) Module: Loaded MS-CHAP mschap: use_mppe = yes mschap: require_encryption = yes mschap: require_strong = yes mschap: with_ntdomain_hack = yes mschap: passwd = "(null)" mschap: ntlm_auth = "(null)" Module: Instantiated mschap (mschap) Module: Loaded LDAP ldap: server = "127.0.0.1" ldap: port = 389 ldap: net_timeout = 1 ldap: timeout = 4 ldap: timelimit = 3 ldap: identity = "cn=radius,ou=staff,dc=ml,dc=mbox,dc=it" ldap: tls_mode = no ldap: start_tls = no ldap: tls_cacertfile = "(null)" ldap: tls_cacertdir = "(null)" ldap: tls_certfile = "(null)" ldap: tls_keyfile = "(null)" ldap: tls_randfile = "(null)" ldap: tls_require_cert = "allow" ldap: password = "radius" ldap: basedn = "dc=ml,dc=mbox,dc=it" 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 = "(null)" ldap: groupname_attribute = "cn" ldap: groupmembership_filter = "(|(&(objectClass=GroupOfNames)(member= %{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember= %{Ldap-UserDn})))" ldap: groupmembership_attribute = "radiusGroupName" ldap: dictionary_mapping = "/etc/raddb/ldap.attrmap" ldap: ldap_debug = 0 ldap: ldap_connections_number = 5 ldap: compare_check_items = no ldap: access_attr_used_for_allow = yes ldap: do_xlat = no ldap: set_auth_type = yes 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 /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 sambaLMPassword mapped to RADIUS LM-Password rlm_ldap: LDAP sambaNTPassword mapped to RADIUS NT-Password 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 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 radiusPortLimit mapped to RADIUS Port-Limit rlm_ldap: LDAP radiusReplyMessage mapped to RADIUS Reply-Message rlm_ldap: LDAP radiusTunnelType mapped to RADIUS Tunnel-Type rlm_ldap: LDAP radiusTunnelMediumType mapped to RADIUS Tunnel-Medium-Type rlm_ldap: LDAP radiusTunnelPrivateGroupId mapped to RADIUS Tunnel-Private-Group-Id rlm_ldap: LDAP radiusTunnelPassword mapped to RADIUS Tunnel-Password conns: 0xb9af3668 Module: Instantiated ldap (ldap) 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 = "/etc/raddb/huntgroups" preprocess: hints = "/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 = yes preprocess: with_alvarion_vsa_hack = no Module: Instantiated preprocess (preprocess) Module: Loaded detail detail: detailfile = "%A/%{Client-IP-Address}/detail" detail: detailperm = 384 detail: dirperm = 493 detail: locking = no Module: Instantiated detail (auth_log) 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 = "/etc/raddb/users" files: acctusersfile = "/etc/raddb/acct_users" files: preproxy_usersfile = "/etc/raddb/preproxy_users" files: compat = "cistron" [/etc/raddb/users]:86 Cistron compatibility checks for entry DEFAULT ... [/etc/raddb/users]:98 Cistron compatibility checks for entry DEFAULT ... [/etc/raddb/users]:123 Cistron compatibility checks for entry DEFAULT ... [/etc/raddb/users]:135 Cistron compatibility checks for entry DEFAULT ... [/etc/raddb/users]:141 Cistron compatibility checks for entry DEFAULT ... [/etc/raddb/users]:147 Cistron compatibility checks for entry DEFAULT ... [/etc/raddb/users]:157 Cistron compatibility checks for entry max ... [/etc/raddb/users]:167 Cistron compatibility checks for entry DEFAULT ... Module: Instantiated files (files) 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 radutmp radutmp: filename = "/var/log/radius/radutmp" radutmp: username = "%{User-Name}" radutmp: case_sensitive = yes radutmp: check_with_nas = yes radutmp: perm = 384 radutmp: callerid = yes Module: Instantiated radutmp (radutmp) Module: Loaded SQL sql: driver = "rlm_sql_postgresql" sql: server = "localhost" sql: port = "" sql: login = "radius" sql: password = "radius" sql: radius_db = "radius" sql: nas_table = "nas" sql: sqltrace = no sql: sqltracefile = "/var/log/radius/sqltrace.sql" sql: readclients = no sql: deletestalesessions = yes sql: num_sql_socks = 5 sql: sql_user_name = "%{User-Name}" sql: default_user_profile = "" sql: query_on_not_found = no sql: authorize_check_query = "SELECT id, UserName, Attribute, Value, Op ??FROM radcheck ??WHERE Username = '%{SQL-User-Name}' ??ORDER BY id" sql: authorize_reply_query = "SELECT id, UserName, Attribute, Value, Op ??FROM radreply ??WHERE Username = '%{SQL-User-Name}' ??ORDER BY id" sql: authorize_group_check_query = "SELECT radgroupcheck.id, radgroupcheck.GroupName, ??radgroupcheck.Attribute, radgroupcheck.Value,radgroupcheck.Op ??FROM radgroupcheck, usergroup ??WHERE usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName = radgroupcheck.GroupName ??ORDER BY radgroupcheck.id" sql: authorize_group_reply_query = "SELECT radgroupreply.id, radgroupreply.GroupName, radgroupreply.Attribute, ??radgroupreply.Value, radgroupreply.Op ??FROM radgroupreply,usergroup ??WHERE usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName = radgroupreply.GroupName ??ORDER BY radgroupreply.id" sql: accounting_onoff_query = "UPDATE radacct SET AcctStopTime = ('% S'::timestamp - '%{Acct-Delay-Time:-0}'::interval), AcctSessionTime = (EXTRACT(EPOCH FROM('%S'::timestamp with time zone - AcctStartTime::timestamp with time zone - '%{Acct-Delay-Time:-0}'::interval)))::BIGINT, AcctTerminateCause='%{Acct-Terminate-Cause}', AcctStopDelay = 0 WHERE AcctSessionTime IS NULL AND AcctStopTime IS NULL AND NASIPAddress= '%{NAS-IP-Address}' AND AcctStartTime <= '% S'::timestamp" sql: accounting_update_query = "UPDATE radacct SET FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, AcctSessionTime = (EXTRACT(EPOCH FROM('%S'::timestamp with time zone - AcctStartTime::timestamp with time zone - '%{Acct-Delay-Time:-0}'::interval)))::BIGINT, AcctInputOctets = (('%{Acct-Input-Gigawords:-0}'::bigint << 32) + '%{Acct-Input-Octets:-0}'::bigint), AcctOutputOctets = (('%{Acct-Output-Gigawords:-0}'::bigint << 32) + '%{Acct-Output-Octets:-0}'::bigint) WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress= '%{NAS-IP-Address}' AND AcctStopTime IS NULL" sql: accounting_update_query_alt = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctSessionTime, AcctAuthentic, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, ??ServiceType, FramedProtocol, FramedIPAddress, XAscendSessionSvrKey) ??values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', ??'%{NAS-Port}', '%{NAS-Port-Type}', ('%S'::timestamp - '%{Acct-Delay-Time:-0}'::interval - '%{Acct-Session-Time:-0}'::interval), ??'%{Acct-Session-Time}', '%{Acct-Authentic}', ??(('%{Acct-Input-Gigawords:-0}'::bigint << 32) + '%{Acct-Input-Octets:-0}'::bigint), ??(('%{Acct-Output-Gigawords:-0}'::bigint << 32) + '%{Acct-Output-Octets:-0}'::bigint), '%{Called-Station-Id}', ??'%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', ??NULLIF('%{Framed-IP-Address}', '')::inet, '%{X-Ascend-Session-Svr-Key}')" sql: accounting_start_query = "INSERT into radacct ??(AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctAuthentic, ??ConnectInfo_start, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, XAscendSessionSvrKey) ??values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', ??'%{NAS-Port}', '%{NAS-Port-Type}', ('% S'::timestamp - '%{Acct-Delay-Time:-0}'::interval), '%{Acct-Authentic}', '%{Connect-Info}', ??'%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', ??NULLIF('%{Framed-IP-Address}', '')::inet, 0, '%{X-Ascend-Session-Svr-Key}')" sql: accounting_start_query_alt = "UPDATE radacct ??SET AcctStartTime = ('%S'::timestamp - '%{Acct-Delay-Time:-0}'::interval), AcctStartDelay = 0, ??ConnectInfo_start = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' ??AND NASIPAddress = '%{NAS-IP-Address}' AND AcctStopTime IS NULL" sql: accounting_stop_query = "UPDATE radacct ??SET AcctStopTime = ('% S'::timestamp - '%{Acct-Delay-Time:-0}'::interval), ??AcctSessionTime = NULLIF('%{Acct-Session-Time}', '')::bigint, ??AcctInputOctets = (('%{Acct-Input-Gigawords:-0}'::bigint << 32) + '%{Acct-Input-Octets:-0}'::bigint), ??AcctOutputOctets = (('%{Acct-Output-Gigawords:-0}'::bigint << 32) + '%{Acct-Output-Octets:-0}'::bigint), ??AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay = 0, ??FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, ConnectInfo_stop = '%{Connect-Info}' ??WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' ??AND NASIPAddress = '%{NAS-IP-Address}' AND AcctStopTime IS NULL" sql: accounting_stop_query_alt = "INSERT into radacct ??(AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctStopTime, ??AcctSessionTime, AcctAuthentic, ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, ??AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, AcctStopDelay) ??values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', ??'%{NAS-Port}', '%{NAS-Port-Type}', ('% S'::timestamp - '%{Acct-Delay-Time:-0}'::interval - '%{Acct-Session-Time:-0}'::interval), ??('%S'::timestamp - '%{Acct-Delay-Time:-0}'::interval), NULLIF('%{Acct-Session-Time}', '')::bigint, ??'%{Acct-Authentic}', '%{Connect-Info}', ??(('%{Acct-Input-Gigawords:-0}'::bigint << 32) + '%{Acct-Input-Octets:-0}'::bigint), ??(('%{Acct-Output-Gigawords:-0}'::bigint << 32) + '%{Acct-Output-Octets:-0}'::bigint), '%{Called-Station-Id}', ??'%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', ??NULLIF('%{Framed-IP-Address}', '')::inet, 0)" sql: group_membership_query = "SELECT GroupName FROM usergroup WHERE UserName='%{SQL-User-Name}'" sql: connect_failure_retry_delay = 60 sql: simul_count_query = "" sql: simul_verify_query = "" sql: postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ('%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW())" sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" rlm_sql (sql): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked rlm_sql (sql): Attempting to connect to radius@localhost:/radius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_postgresql #4 rlm_sql (sql): Connected new DB handle, #4 Module: Instantiated sql (sql) main: smux_password = "" main: snmp_write_access = no SMUX connect try 1 SMUX open oid: 1.3.6.1.4.1.3317.1.3.1 SMUX open progname: radiusd SMUX open password: SMUX register oid: 1.3.6.1.2.1.67.1.1.1.1 SMUX register priority: -1 SMUX register operation: 1 SMUX register oid: 1.3.6.1.2.1.67.2.1.1.1 SMUX register priority: -1 SMUX register operation: 1 Initializing the thread pool... thread: start_servers = 5 thread: max_servers = 32 thread: min_spare_servers = 3 thread: max_spare_servers = 10 thread: max_requests_per_server = 0 thread: cleanup_delay = 5 Thread 1 waiting to be assigned a request Thread spawned new child 1. Total threads in pool: 1 Thread 2 waiting to be assigned a request Thread spawned new child 2. Total threads in pool: 2 Thread 3 waiting to be assigned a request Thread spawned new child 3. Total threads in pool: 3 Thread 4 waiting to be assigned a request Thread spawned new child 4. Total threads in pool: 4 Thread 5 waiting to be assigned a request Thread spawned new child 5. Total threads in pool: 5 Thread pool initialized Listening on authentication 192.168.0.10:1812 Listening on accounting 192.168.0.10:1813 Ready to process requests. SMUX read start SMUX read len: 12 SMUX message received type: 67 rest len: 4 SMUX_RRSP SMUX_RRSP value: 0 errstat: 0 --- Walking the entire request list --- Nothing to do. Sleeping until we see a request. Threads: total/active/spare threads = 5/0/5 Regards, Massimo Meregalli
Massimo Meregalli wrote:
The following is the backtrace produced when I attach the debugger to the radiusd process:
(gdb) backtrace #0 0x0012d402 in __kernel_vsyscall () #1 0x00166a0e in __lll_mutex_lock_wait () from /lib/libpthread.so.0 #2 0x00162883 in _L_mutex_lock_79 () from /lib/libpthread.so.0 #3 0x001623ad in pthread_mutex_lock () from /lib/libpthread.so.0 #4 0x00704e6d in ldap_pvt_thread_mutex_lock () from /usr/lib/libldap_r-2.3.so.0
Pretty much what I expected. The LDAP code is blocking on a mutex. Why, I don't know.
#5 0x0070f79b in ldap_ld_free () from /usr/lib/libldap_r-2.3.so.0 #6 0x00663dd7 in ?? () from /usr/lib/libnss_ldap.so.2 #7 0x00667504 in ?? () from /usr/lib/libnss_ldap.so.2
libnss_ldap? Huh? Where did that come from? Are you trying to get passwords via the "unix" module, over NSS, using LDAP? I suggest commenting out the "unix" module from radiusd.conf. The issue MAY be conflicting use of static variables in the OpenLDAP libraries. i.e. The OpenLDAP libraries can connect to *one* LDAP server. Not two, *one*. So if you use rlm_ldap, you *cannot* lookup usernames and passwords in LDAP, via NSS. The OpenLDAP libraries will break... possibly exactly like this. Alan DeKok.
Hi Alan, Thanks for your replies.
#5 0x0070f79b in ldap_ld_free () from /usr/lib/libldap_r-2.3.so.0 #6 0x00663dd7 in ?? () from /usr/lib/libnss_ldap.so.2 #7 0x00667504 in ?? () from /usr/lib/libnss_ldap.so.2
libnss_ldap? Huh? Where did that come from?
Are you trying to get passwords via the "unix" module, over NSS, using LDAP?
The server on which the radiusd is running is configured to authenticate users against ldap (via pam) (which is running on the same machine as the radiusd server). The ldap server is used only to store user information. The passwords are stored into a kerberos database. The User-Password ldap attribute is specified as {SASL}<user>@REALM for those application that don't understand kerberos and the server is also running saslauthd. All the other application the server is running which use ldap as database are working fine.
I suggest commenting out the "unix" module from radiusd.conf. The issue MAY be conflicting use of static variables in the OpenLDAP libraries.
The unix module is commented out in the configuration file. Regards, Massimo Meregalli
Massimo Meregalli wrote:
The server on which the radiusd is running is configured to authenticate users against ldap (via pam) (which is running on the same machine as the radiusd server). The ldap server is used only to store user information. The passwords are stored into a kerberos database. The User-Password ldap attribute is specified as {SASL}<user>@REALM for those application that don't understand kerberos and the server is also running saslauthd.
Yes... that doesn't change what I said. The OpenLDAP libraries have some static variables that make it impossible to *safely* talk to two LDAP servers from the same program. This is likely the issue you are running into.
All the other application the server is running which use ldap as database are working fine.
Are they also using LDAP via PAM? If not, then they are not running into the problem I pointed out.
The unix module is commented out in the configuration file.
Whatever. You're using rlm_ldap AND ldap through PAM. This is not supported by the OpenLDAP libraries. It was magic why it worked before. It works in non-threaded mode because the conflicting mutexes aren't used. Alan DeKok.
On Wed, 2007-11-07 at 21:20 +0100, Massimo Meregalli wrote:
Hi Alan,
Thanks for your replies.
#5 0x0070f79b in ldap_ld_free () from /usr/lib/libldap_r-2.3.so.0 #6 0x00663dd7 in ?? () from /usr/lib/libnss_ldap.so.2 #7 0x00667504 in ?? () from /usr/lib/libnss_ldap.so.2
libnss_ldap? Huh? Where did that come from?
Are you trying to get passwords via the "unix" module, over NSS, using LDAP?
The server on which the radiusd is running is configured to authenticate users against ldap (via pam) (which is running on the same machine as the radiusd server). The ldap server is used only to store user information. The passwords are stored into a kerberos database. The User-Password ldap attribute is specified as {SASL}<user>@REALM for those application that don't understand kerberos and the server is also running saslauthd.
All the other application the server is running which use ldap as database are working fine.
Well, regardless; the backtrace CLEARLY shows the problem is in libnss_ldap i.e. outside FreeRadius. Are you running nscd? If not, I suggest trying it. That way, the NSS ldap lookups will happen in the nscd process, and libc should detect that nscd is running and connect to the unix socket before even *thinking* about loading the libraries from nssswitch.conf It is possible that using the LDAP APIs in a certain way is the trigger, which is why other applications seem fine.
Hi Phil, Alan I've tries to start nscd and that seems to resolve the problem. I'd would like to thanks you for all your answers. Regards, Massimo Meregalli
Are you running nscd? If not, I suggest trying it. That way, the NSS ldap lookups will happen in the nscd process, and libc should detect that nscd is running and connect to the unix socket before even *thinking* about loading the libraries from nssswitch.conf
It is possible that using the LDAP APIs in a certain way is the trigger, which is why other applications seem fine.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (3)
-
Alan DeKok -
Massimo Meregalli -
Phil Mayers