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