February 2013 - Freeradius-Users - lists.freeradius.org

LDAP groups and profiles
by Chris Taylor 07 Feb '13

07 Feb '13

I have RADIUS running with multiple realms and multiple LDAP back ends that stores all my user attributes. I am trying to apply different user profiles to different groups. What I did was setup the profile in the USERS file, add the group attributes to the ldap config file, and on the user's LDAP account I added the attribute radiusGroupName with the value "residential_profile", but I can't seem to get it to work correctly. It doesn't seem to query the correct backend. I am sure that I have something wrong but I am not sure what I looked at rlm_ldap and searched the archive list but haven't been able to find anything any help would be appreciated. This is what my configuration files look like; USERS DEFAULT Ldap-Group == residential_profile Service-Type = Framed-User, Framed-Protocol = PPP, Cisco-AVPair += "ip:inacl#100=permit tcp any x.x.x.x 0.0.0.15 eq 25", Cisco-AVPair += "ip:inacl#200=deny tcp any any eq 25", Cisco-AVPair += "ip:inacl#300=permit ip any any", Fall-Through = No ldap ldap2.REALM-2.ca { basedn = "ou=radius,o=REALM-2.ca,dc=container,dc=ca" filter = "(&(uid=%{%{Stripped-User-Name}:-%{User-Name}})(objectclass=posixAccount)(cn=true))" ldap ldap1.REALM-1.ca { basedn = "ou=radius,o=REALM-1.ca,dc=container,dc=ca" filter = "(&(uid=%{%{Stripped-User-Name}:-%{User-Name}})(objectclass=posixAccount)(cn=true))" groupname_attribute = cn groupmembership_filter = "(|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn})))" groupmembership_attribute = radiusGroupName Output from radius -X [files] users: Matched entry DEFAULT at line 214 [ldap2.REALM-2.ca] Entering ldap_groupcmp() [files] expand: ou=radius,o=REALM-2.ca,dc=container,dc=ca -> ou=radius,o= REALM-2ca,dc= container,dc=ca [files] expand: %{Stripped-User-Name} -> 112boy [files] expand: (&(uid=%{%{Stripped-User-Name}:-%{User-Name}})(objectclass=posixAccount)(cn=true)) -> (&(uid=112boy)(objectclass=posixAccount)(cn=true)) [ldap2. REALM-2.ca] ldap_get_conn: Checking Id: 0 [ldap2. REALM-2.ca] ldap_get_conn: Got Id: 0 [ldap2. REALM-2.ca] attempting LDAP reconnection [ldap2. REALM-2.ca] Bind was successful [ldap2. REALM-2.ca] performing search in ou=radius,o= REALM-2.ca,dc= container,dc=ca, with filter (&(uid=112boy)(objectclass=posixAccount)(cn=true)) [ldap2. REALM-2.ca] object not found rlm_ldap::ldap_groupcmp: search failed [ldap2. REALM-2.ca] ldap_release_conn: Release Id: 0 Thanks, Chris

3 5

Re: Degradation of service when authentication fails with Windows AD
by Antonio Alberola 07 Feb '13

07 Feb '13

> The PAM APIs are synchronous, and don't offer timeout options. > It's not possible to timeout a PAM call; FreeRADIUS is entirely > at the mercy of PAM. > > Don't use PAM, it's not suitable for your needs. Use "ntlm_auth", > and FreeRADIUS can timeout the call. We migrated to PAM when the problems started. Previously we used "ntlm_auth" and the problem appeared more frequently. I also recommended using PAM-Kerberos because they said it was better integrated with Windows. Is "ntlm_auth" the best way to authenticate with Windows AD? We have several domains to authenticate and need stability in case one of them does not respond.

2 1

pb with realm
by Hocine M 07 Feb '13

07 Feb '13

Hi , I have a problem with some user proxied. In the accounting-request the username is stripped and realm is NULL. Why le realm is lost? here is le debug output. rad_recv: Access-Request packet from host 192.168.58.5 port 20007, id=13, length=256 NAS-Port-Id = "AP59/1" Calling-Station-Id = "98-0C-82-A0-9C-53" Called-Station-Id = "00-26-3E-70-6F-C0:eduroam" Service-Type = Framed-User User-Name = "pierre.dupont(a)univ-lille1.fr" NAS-Port = 13815 State = 0xce6b1f07c76006eefba5daa495da75ed EAP-Message = 0x020b005019001703010020c523a88c2350d93086ec64726de2c365f717579f7b45e134cdc419b070885ab1170301002088cce6caf3b1d263d7731cb2b8c1c6e20b1967450888d652b5dc399cd6c8fe1a NAS-Port-Type = Wireless-802.11 NAS-IP-Address = 192.168.58.5 NAS-Identifier = "Trapeze" Message-Authenticator = 0x318ab29add69625365a854e67782de40 Wed Feb 6 10:08:07 2013 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:07 2013 : Info: +- entering group authorize {...} Wed Feb 6 10:08:07 2013 : Info: ++[preprocess] returns ok Wed Feb 6 10:08:07 2013 : Info: ++? if (User-name !~ /^([^@]*)@(.+)$/) Wed Feb 6 10:08:07 2013 : Info: ? Evaluating (User-name !~ /^([^@]*)@(.+)$/) -> FALSE Wed Feb 6 10:08:07 2013 : Info: ++? if (User-name !~ /^([^@]*)@(.+)$/) -> FALSE Wed Feb 6 10:08:07 2013 : Info: ++- entering else else {...} Wed Feb 6 10:08:07 2013 : Info: +++[ok] returns ok Wed Feb 6 10:08:07 2013 : Info: ++- else else returns ok Wed Feb 6 10:08:07 2013 : Info: ++[mschap] returns noop Wed Feb 6 10:08:07 2013 : Info: [suffix] Looking up realm "univ-lille1.fr" for User-Name = "pierre.dupont(a)univ-lille1.fr" Wed Feb 6 10:08:07 2013 : Info: [suffix] Found realm "~.+$" Wed Feb 6 10:08:07 2013 : Info: [suffix] Adding Realm = "univ-lille1.fr" Wed Feb 6 10:08:07 2013 : Info: [suffix] Proxying request from user pierre.dupont to realm ~.+$ Wed Feb 6 10:08:07 2013 : Info: [suffix] Preparing to proxy authentication request to realm "~.+$" Wed Feb 6 10:08:07 2013 : Info: ++[suffix] returns updated Wed Feb 6 10:08:07 2013 : Info: [eap] Request is supposed to be proxied to Realm ~.+$. Not doing EAP. Wed Feb 6 10:08:07 2013 : Info: ++[eap] returns noop Wed Feb 6 10:08:07 2013 : Info: ++[pap] returns noop Wed Feb 6 10:08:07 2013 : Info: # Executing section pre-proxy from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:07 2013 : Info: +- entering group pre-proxy {...} Wed Feb 6 10:08:07 2013 : Info: [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.58.5/pre-proxy-detail-20130206 Wed Feb 6 10:08:07 2013 : Info: [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.58.5/pre-proxy-detail-20130206 Wed Feb 6 10:08:07 2013 : Info: [pre_proxy_log] expand: %t -> Wed Feb 6 10:08:07 2013 Wed Feb 6 10:08:07 2013 : Info: ++[pre_proxy_log] returns ok Wed Feb 6 10:08:07 2013 : Info: ++? if (Packet-Type != Accounting-Request) Wed Feb 6 10:08:07 2013 : Info: ? Evaluating (Packet-Type != Accounting-Request) -> FALSE Wed Feb 6 10:08:07 2013 : Info: ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 223 to 193.51.224.109 port 1812 NAS-Port-Id = "AP59/1" Calling-Station-Id = "98-0C-82-A0-9C-53" Called-Station-Id = "00-26-3E-70-6F-C0:eduroam" Service-Type = Framed-User User-Name = "pierre.dupont(a)univ-lille1.fr" NAS-Port = 13815 State = 0xce6b1f07c76006eefba5daa495da75ed EAP-Message = 0x020b005019001703010020c523a88c2350d93086ec64726de2c365f717579f7b45e134cdc419b070885ab1170301002088cce6caf3b1d263d7731cb2b8c1c6e20b1967450888d652b5dc399cd6c8fe1a NAS-Port-Type = Wireless-802.11 NAS-IP-Address = 192.168.58.5 NAS-Identifier = "Trapeze" Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3133 Wed Feb 6 10:08:07 2013 : Info: Proxying request 223 to home server 193.51.224.109 port 1812 Sending Access-Request of id 223 to 193.51.224.109 port 1812 NAS-Port-Id = "AP59/1" Calling-Station-Id = "98-0C-82-A0-9C-53" Called-Station-Id = "00-26-3E-70-6F-C0:eduroam" Service-Type = Framed-User User-Name = "pierre.dupont(a)univ-lille1.fr" NAS-Port = 13815 State = 0xce6b1f07c76006eefba5daa495da75ed EAP-Message = 0x020b005019001703010020c523a88c2350d93086ec64726de2c365f717579f7b45e134cdc419b070885ab1170301002088cce6caf3b1d263d7731cb2b8c1c6e20b1967450888d652b5dc399cd6c8fe1a NAS-Port-Type = Wireless-802.11 NAS-IP-Address = 192.168.58.5 NAS-Identifier = "Trapeze" Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3133 Wed Feb 6 10:08:07 2013 : Debug: Going to the next request Wed Feb 6 10:08:07 2013 : Debug: Waking up in 0.9 seconds. rad_recv: Access-Accept packet from host 193.51.224.109 port 1812, id=223, length=182 User-Name = "pierre.dupont\000" MS-MPPE-Recv-Key = 0x948d791f2da3af530868839e7df666aa1886290c40bfe70643d3cc079f9c24f4 MS-MPPE-Send-Key = 0x0a525d10d48467385a134bf6b1c4bee916e17fd24016a6f6c01b35ef243f07b2 EAP-Message = 0x030b0004 Message-Authenticator = 0xf6f125f6e9767f4dc8f9decb26a31021 Proxy-State = 0x3133 Wed Feb 6 10:08:07 2013 : Info: # Executing section post-proxy from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:07 2013 : Info: +- entering group post-proxy {...} Wed Feb 6 10:08:07 2013 : Info: [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.58.5/post-proxy-detail-20130206 Wed Feb 6 10:08:07 2013 : Info: [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.58.5/post-proxy-detail-20130206 Wed Feb 6 10:08:07 2013 : Info: [post_proxy_log] expand: %t -> Wed Feb 6 10:08:07 2013 Wed Feb 6 10:08:07 2013 : Info: ++[post_proxy_log] returns ok Wed Feb 6 10:08:07 2013 : Info: [eap] No pre-existing handler found Wed Feb 6 10:08:07 2013 : Info: ++[eap] returns noop Wed Feb 6 10:08:07 2013 : Info: Found Auth-Type = Accept Wed Feb 6 10:08:07 2013 : Info: Auth-Type = Accept, accepting the user Wed Feb 6 10:08:07 2013 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:07 2013 : Info: +- entering group post-auth {...} Wed Feb 6 10:08:07 2013 : Info: [linelog] expand: %{reply:Packet-Type} -> Access-Accept Wed Feb 6 10:08:07 2013 : Info: [linelog] expand: %{%{reply:Packet-Type}:-format} -> Access-Accept Wed Feb 6 10:08:07 2013 : Info: [linelog] expand: /var/log/freeradius/linelog.log -> /var/log/freeradius/linelog.log Wed Feb 6 10:08:07 2013 : Info: [linelog] expand: %S %{reply:Packet-Type} %{Packet-Src-IP-Address} %{NAS-IP-Address} %{Client-Shortname} %{User-Name} %{Calling-Station-Id} %{Called-Station-Id} -> 2013-02-06 10:08:07 Access-Accept 192.168.58.5 192.168.58.5 MX800R-2 pierre.dupont(a)univ-lille1.fr 98-0C-82-A0-9C-53 00-26-3E-70-6F-C0:eduroam Wed Feb 6 10:08:07 2013 : Info: ++[linelog] returns ok Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand: %{reply:Packet-Type} -> Access-Accept Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand: f_ticks.%{%{reply:Packet-Type}:-format} -> f_ticks.Access-Accept Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand: /var/log/freeradius/f_ticks.log -> /var/log/freeradius/f_ticks.log Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand: %S - F-TICKS/eduroam/1.0#REALM=%{Realm}#VISCOUNTRY=FR#VISINST=LILLE3#CSI=%{Calling-Station-Id}#RESULT=OK -> 2013-02-06 10:08:07 - F-TICKS/eduroam/1.0#REALM=univ-lille1.fr#VISCOUNTRY=FR#VISINST=LILLE3#CSI=98-0C-82-A0-9C-53#RESULT=OK Wed Feb 6 10:08:07 2013 : Info: ++[f_ticks] returns ok Wed Feb 6 10:08:07 2013 : Info: expand: %{Realm} -> univ-lille1.fr Wed Feb 6 10:08:07 2013 : Info: ++- entering switch %{Realm} {...} Wed Feb 6 10:08:07 2013 : Info: +++- switch %{Realm} returns noop Wed Feb 6 10:08:07 2013 : Info: ++- group post-auth returns noop Wed Feb 6 10:08:07 2013 : Info: ++? if (("%{Realm}" !~ /^(ext\.|etu\.|)univ-lille3\.fr$/) && ("%{Called-Station-Id}" =~ /^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/)) Wed Feb 6 10:08:07 2013 : Info: expand: %{Realm} -> univ-lille1.fr Wed Feb 6 10:08:07 2013 : Info: ?? Evaluating ("%{Realm}" !~ /^(ext\.|etu\.|)univ-lille3\.fr$/) -> TRUE Wed Feb 6 10:08:07 2013 : Info: expand: %{Called-Station-Id} -> 00-26-3E-70-6F-C0:eduroam Wed Feb 6 10:08:07 2013 : Info: ?? Evaluating ("%{Called-Station-Id}" =~ /^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/) -> TRUE Wed Feb 6 10:08:07 2013 : Info: ++? if (("%{Realm}" !~ /^(ext\.|etu\.|)univ-lille3\.fr$/) && ("%{Called-Station-Id}" =~ /^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/)) -> TRUE Wed Feb 6 10:08:07 2013 : Info: ++- entering if (("%{Realm}" !~ /^(ext\.|etu\.|)univ-lille3\.fr$/) && ("%{Called-Station-Id}" =~ /^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/)) {...} Wed Feb 6 10:08:07 2013 : Info: +++[reply] returns noop Wed Feb 6 10:08:07 2013 : Info: ++- if (("%{Realm}" !~ /^(ext\.|etu\.|)univ-lille3\.fr$/) && ("%{Called-Station-Id}" =~ /^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/)) returns noop Wed Feb 6 10:08:07 2013 : Info: ++[exec] returns noop Sending Access-Accept of id 13 to 192.168.58.5 port 20007 User-Name = "pierre.dupont\000" MS-MPPE-Recv-Key = 0x948d791f2da3af530868839e7df666aa1886290c40bfe70643d3cc079f9c24f4 MS-MPPE-Send-Key = 0x0a525d10d48467385a134bf6b1c4bee916e17fd24016a6f6c01b35ef243f07b2 EAP-Message = 0x030b0004 Message-Authenticator = 0x00000000000000000000000000000000 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "56" Wed Feb 6 10:08:07 2013 : Info: Finished request 223. Wed Feb 6 10:08:07 2013 : Debug: Going to the next request Wed Feb 6 10:08:07 2013 : Debug: Waking up in 1.5 seconds. rad_recv: Accounting-Request packet from host 192.168.58.5 port 20007, id=14, length=222 Acct-Status-Type = Start Acct-Authentic = RADIUS Acct-Multi-Session-Id = "SESS-13815-54b752-141653-ef2" Acct-Session-Id = "SESS-13815-54b752-141653-ef2" User-Name = "pierre.dupont" Event-Timestamp = "Feb 6 2013 10:08:07 CET" Trapeze-VLAN-Name = "EduExterieurs" Calling-Station-Id = "98-0C-82-A0-9C-53" NAS-Port-Id = "AP59/1" Called-Station-Id = "00-26-3E-70-6F-C0:eduroam" NAS-Port = 13815 NAS-Port-Type = Wireless-802.11 NAS-IP-Address = 192.168.58.5 NAS-Identifier = "Trapeze" Acct-Delay-Time = 0 Wed Feb 6 10:08:07 2013 : Info: # Executing section preacct from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:07 2013 : Info: +- entering group preacct {...} Wed Feb 6 10:08:07 2013 : Info: ++[preprocess] returns ok Wed Feb 6 10:08:07 2013 : Info: [linelog] expand: %{reply:Packet-Type} -> 0 Wed Feb 6 10:08:07 2013 : Info: [linelog] expand: %{%{reply:Packet-Type}:-format} -> 0 Wed Feb 6 10:08:07 2013 : Debug: WARNING: No such configuration item .0 Wed Feb 6 10:08:07 2013 : Info: [linelog] No such entry ".0" Wed Feb 6 10:08:07 2013 : Info: ++[linelog] returns noop Wed Feb 6 10:08:07 2013 : Info: [acct_unique] Hashing 'NAS-Port = 13815,Client-IP-Address = 192.168.58.5,NAS-IP-Address = 192.168.58.5,Acct-Session-Id = "SESS-13815-54b752-141653-ef2",User-Name = "pierre.dupont"' Wed Feb 6 10:08:07 2013 : Info: [acct_unique] Acct-Unique-Session-ID = "98d6d9a9c729efc3". Wed Feb 6 10:08:07 2013 : Info: ++[acct_unique] returns ok Wed Feb 6 10:08:07 2013 : Info: [suffix] No '@' in User-Name = "pierre.dupont", looking up realm NULL Wed Feb 6 10:08:07 2013 : Info: [suffix] Found realm "NULL" Wed Feb 6 10:08:07 2013 : Info: [suffix] Adding Stripped-User-Name = "pierre.dupont" Wed Feb 6 10:08:07 2013 : Info: [suffix] Adding Realm = "NULL" Wed Feb 6 10:08:07 2013 : Info: [suffix] Accounting realm is LOCAL. Wed Feb 6 10:08:07 2013 : Info: ++[suffix] returns ok Wed Feb 6 10:08:07 2013 : Info: # Executing section accounting from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:07 2013 : Info: +- entering group accounting {...} Wed Feb 6 10:08:07 2013 : Info: [detail] expand: %{Packet-Src-IP-Address} -> 192.168.58.5 Wed Feb 6 10:08:07 2013 : Info: [detail] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.58.5/detail-20130206 Wed Feb 6 10:08:07 2013 : Info: [detail] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.58.5/detail-20130206 Wed Feb 6 10:08:07 2013 : Info: [detail] expand: %t -> Wed Feb 6 10:08:07 2013 Wed Feb 6 10:08:07 2013 : Info: ++[detail] returns ok Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand: %{User-Name} -> pierre.dupont Wed Feb 6 10:08:07 2013 : Info: [sql_acct] sql_set_user escaped user --> 'pierre.dupont' Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand: %{Acct-Delay-Time} -> 0 Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand: INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql Wed Feb 6 10:08:07 2013 : Debug: rlm_sql (sql_acct): Reserving sql socket id: 5 Wed Feb 6 10:08:07 2013 : Debug: rlm_sql_mysql: query: INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('SESS-13815-54b752-141653-ef2', '98d6d9a9c729efc3', 'pierre.dupont', 'NULL', '192.168.58.5', '13815', 'Wireless-802.11', '2013-02-06 10:08:07', NULL, '0', 'RADIUS', '', '', '0', '0', '00-26-3E-70-6F-C0:eduroam', '98-0C-82-A0-9C-53', '', '', '', '', '0', '0', '') Wed Feb 6 10:08:07 2013 : Debug: rlm_sql (sql_acct): Released sql socket id: 5 Wed Feb 6 10:08:07 2013 : Info: ++[sql_acct] returns ok Wed Feb 6 10:08:07 2013 : Info: ++[exec] returns noop Wed Feb 6 10:08:07 2013 : Info: [attr_filter.accounting_response] expand: %{User-Name} -> pierre.dupont Wed Feb 6 10:08:07 2013 : Debug: attr_filter: Matched entry DEFAULT at line 12 Wed Feb 6 10:08:07 2013 : Info: ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 14 to 192.168.58.5 port 20007 Wed Feb 6 10:08:07 2013 : Info: Finished request 224. Wed Feb 6 10:08:07 2013 : Info: Cleaning up request 224 ID 14 with timestamp +229 Wed Feb 6 10:08:07 2013 : Debug: Going to the next request Wed Feb 6 10:08:07 2013 : Debug: Waking up in 1.4 seconds. rad_recv: Accounting-Request packet from host 192.168.58.5 port 20007, id=16, length=258 Acct-Status-Type = Interim-Update Acct-Authentic = RADIUS Acct-Multi-Session-Id = "SESS-13815-54b752-141653-ef2" Acct-Session-Id = "SESS-13815-54b752-141653-ef2" User-Name = "pierre.dupont" Event-Timestamp = "Feb 6 2013 10:08:09 CET" Trapeze-VLAN-Name = "EduExterieurs" Calling-Station-Id = "98-0C-82-A0-9C-53" NAS-Port-Id = "AP59/1" Called-Station-Id = "00-26-3E-70-6F-C0:eduroam" NAS-Port = 13815 Framed-IP-Address = 10.56.0.149 Acct-Session-Time = 2 Acct-Output-Octets = 9330 Acct-Input-Octets = 1202 Acct-Output-Packets = 38 Acct-Input-Packets = 230 NAS-Port-Type = Wireless-802.11 NAS-IP-Address = 192.168.58.5 NAS-Identifier = "Trapeze" Acct-Delay-Time = 0 Wed Feb 6 10:08:09 2013 : Info: # Executing section preacct from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:09 2013 : Info: +- entering group preacct {...} Wed Feb 6 10:08:09 2013 : Info: ++[preprocess] returns ok Wed Feb 6 10:08:09 2013 : Info: [linelog] expand: %{reply:Packet-Type} -> 0 Wed Feb 6 10:08:09 2013 : Info: [linelog] expand: %{%{reply:Packet-Type}:-format} -> 0 Wed Feb 6 10:08:09 2013 : Debug: WARNING: No such configuration item .0 Wed Feb 6 10:08:09 2013 : Info: [linelog] No such entry ".0" Wed Feb 6 10:08:09 2013 : Info: ++[linelog] returns noop Wed Feb 6 10:08:09 2013 : Info: [acct_unique] Hashing 'NAS-Port = 13815,Client-IP-Address = 192.168.58.5,NAS-IP-Address = 192.168.58.5,Acct-Session-Id = "SESS-13815-54b752-141653-ef2",User-Name = "pierre.dupont"' Wed Feb 6 10:08:09 2013 : Info: [acct_unique] Acct-Unique-Session-ID = "98d6d9a9c729efc3". Wed Feb 6 10:08:09 2013 : Info: ++[acct_unique] returns ok Wed Feb 6 10:08:09 2013 : Info: [suffix] No '@' in User-Name = "pierre.dupont", looking up realm NULL Wed Feb 6 10:08:09 2013 : Info: [suffix] Found realm "NULL" Wed Feb 6 10:08:09 2013 : Info: [suffix] Adding Stripped-User-Name = "pierre.dupont" Wed Feb 6 10:08:09 2013 : Info: [suffix] Adding Realm = "NULL" Wed Feb 6 10:08:09 2013 : Info: [suffix] Accounting realm is LOCAL. Wed Feb 6 10:08:09 2013 : Info: ++[suffix] returns ok Wed Feb 6 10:08:09 2013 : Info: # Executing section accounting from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:09 2013 : Info: +- entering group accounting {...} Wed Feb 6 10:08:09 2013 : Info: [detail] expand: %{Packet-Src-IP-Address} -> 192.168.58.5 Wed Feb 6 10:08:09 2013 : Info: [detail] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.58.5/detail-20130206 Wed Feb 6 10:08:09 2013 : Info: [detail] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.58.5/detail-20130206 Wed Feb 6 10:08:09 2013 : Info: [detail] expand: %t -> Wed Feb 6 10:08:09 2013 Wed Feb 6 10:08:09 2013 : Info: ++[detail] returns ok Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand: %{User-Name} -> pierre.dupont Wed Feb 6 10:08:09 2013 : Info: [sql_acct] sql_set_user escaped user --> 'pierre.dupont' Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand: %{Acct-Input-Gigawords} -> Wed Feb 6 10:08:09 2013 : Info: [sql_acct] ... expanding second conditional Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand: %{Acct-Input-Octets} -> 1202 Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand: %{Acct-Output-Gigawords} -> Wed Feb 6 10:08:09 2013 : Info: [sql_acct] ... expanding second conditional Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand: %{Acct-Output-Octets} -> 9330 Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand: UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}' -> UPDATE radacct SET framedipaddress = '10.56.0.149', acctsessiontime = '2', acctinputoctets = '0' << 32 | '1202', acctoutputoctets = '0' << 32 | '9330' WHERE acctsessionid = 'SESS-13815-54b752-141653-ef2' AND username = 'yacine Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql Wed Feb 6 10:08:09 2013 : Debug: rlm_sql (sql_acct): Reserving sql socket id: 3 Wed Feb 6 10:08:09 2013 : Debug: rlm_sql_mysql: query: UPDATE radacct SET framedipaddress = '10.56.0.149', acctsessiontime = '2', acctinputoctets = '0' << 32 | '1202', acctoutputoctets = '0' << 32 | '9330' WHERE acctsessionid = 'SESS-13815-54b752-141653-ef2' AND username = 'pierre.dupont' AND nasipaddress = '192.168.58.5' Wed Feb 6 10:08:09 2013 : Debug: rlm_sql (sql_acct): Released sql socket id: 3 Wed Feb 6 10:08:09 2013 : Info: ++[sql_acct] returns ok Wed Feb 6 10:08:09 2013 : Info: ++[exec] returns noop Wed Feb 6 10:08:09 2013 : Info: [attr_filter.accounting_response] expand: %{User-Name} -> pierre.dupont Wed Feb 6 10:08:09 2013 : Debug: attr_filter: Matched entry DEFAULT at line 12 Wed Feb 6 10:08:09 2013 : Info: ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 16 to 192.168.58.5 port 20007 Wed Feb 6 10:08:09 2013 : Info: Finished request 226. Wed Feb 6 10:08:09 2013 : Info: Cleaning up request 226 ID 16 with timestamp +231 Wed Feb 6 10:08:09 2013 : Debug: Going to the next request Wed Feb 6 10:08:09 2013 : Debug: Waking up in 0.1 seconds. Wed Feb 6 10:08:09 2013 : Info: Cleaning up request 216 ID 9 with timestamp +226 Wed Feb 6 10:08:09 2013 : Info: Cleaning up request 217 ID 10 with timestamp +226 Wed Feb 6 10:08:09 2013 : Debug: Waking up in 2.7 seconds. rad_recv: Accounting-Request packet from host 192.168.58.5 port 20007, id=17, length=258 Acct-Status-Type = Interim-Update Acct-Authentic = RADIUS Acct-Multi-Session-Id = "SESS-13815-54b752-141653-ef2" Acct-Session-Id = "SESS-13815-54b752-141653-ef2" User-Name = "pierre.dupont" Event-Timestamp = "Feb 6 2013 10:08:10 CET" Trapeze-VLAN-Name = "EduExterieurs" Calling-Station-Id = "98-0C-82-A0-9C-53" NAS-Port-Id = "AP59/1" Called-Station-Id = "00-26-3E-70-6F-C0:eduroam" NAS-Port = 13815 Framed-IP-Address = 10.71.113.16 Acct-Session-Time = 3 Acct-Output-Octets = 9508 Acct-Input-Octets = 1274 Acct-Output-Packets = 40 Acct-Input-Packets = 234 NAS-Port-Type = Wireless-802.11 NAS-IP-Address = 192.168.58.5 NAS-Identifier = "Trapeze" Acct-Delay-Time = 0 Wed Feb 6 10:08:10 2013 : Info: # Executing section preacct from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:10 2013 : Info: +- entering group preacct {...} Wed Feb 6 10:08:10 2013 : Info: ++[preprocess] returns ok Wed Feb 6 10:08:10 2013 : Info: [linelog] expand: %{reply:Packet-Type} -> 0 Wed Feb 6 10:08:10 2013 : Info: [linelog] expand: %{%{reply:Packet-Type}:-format} -> 0 Wed Feb 6 10:08:10 2013 : Debug: WARNING: No such configuration item .0 Wed Feb 6 10:08:10 2013 : Info: [linelog] No such entry ".0" Wed Feb 6 10:08:10 2013 : Info: ++[linelog] returns noop Wed Feb 6 10:08:10 2013 : Info: [acct_unique] Hashing 'NAS-Port = 13815,Client-IP-Address = 192.168.58.5,NAS-IP-Address = 192.168.58.5,Acct-Session-Id = "SESS-13815-54b752-141653-ef2",User-Name = "pierre.dupont"' Wed Feb 6 10:08:10 2013 : Info: [acct_unique] Acct-Unique-Session-ID = "98d6d9a9c729efc3". Wed Feb 6 10:08:10 2013 : Info: ++[acct_unique] returns ok Wed Feb 6 10:08:10 2013 : Info: [suffix] No '@' in User-Name = "pierre.dupont", looking up realm NULL Wed Feb 6 10:08:10 2013 : Info: [suffix] Found realm "NULL" Wed Feb 6 10:08:10 2013 : Info: [suffix] Adding Stripped-User-Name = "pierre.dupont" Wed Feb 6 10:08:10 2013 : Info: [suffix] Adding Realm = "NULL" Wed Feb 6 10:08:10 2013 : Info: [suffix] Accounting realm is LOCAL. Wed Feb 6 10:08:10 2013 : Info: ++[suffix] returns ok Wed Feb 6 10:08:10 2013 : Info: # Executing section accounting from file /etc/freeradius/sites-enabled/eduroam Wed Feb 6 10:08:10 2013 : Info: +- entering group accounting {...} Wed Feb 6 10:08:10 2013 : Info: [detail] expand: %{Packet-Src-IP-Address} -> 192.168.58.5 Wed Feb 6 10:08:10 2013 : Info: [detail] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.58.5/detail-20130206 Wed Feb 6 10:08:10 2013 : Info: [detail] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.58.5/detail-20130206 Wed Feb 6 10:08:10 2013 : Info: [detail] expand: %t -> Wed Feb 6 10:08:10 2013 Wed Feb 6 10:08:10 2013 : Info: ++[detail] returns ok Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand: %{User-Name} -> pierre.dupont Wed Feb 6 10:08:10 2013 : Info: [sql_acct] sql_set_user escaped user --> 'pierre.dupont' Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand: %{Acct-Input-Gigawords} -> Wed Feb 6 10:08:10 2013 : Info: [sql_acct] ... expanding second conditional Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand: %{Acct-Input-Octets} -> 1274 Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand: %{Acct-Output-Gigawords} -> Wed Feb 6 10:08:10 2013 : Info: [sql_acct] ... expanding second conditional Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand: %{Acct-Output-Octets} -> 9508 Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand: UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}' -> UPDATE radacct SET framedipaddress = '10.71.113.16', acctsessiontime = '3', acctinputoctets = '0' << 32 | '1274', acctoutputoctets = '0' << 32 | '9508' WHERE acctsessionid = 'SESS-13815-54b752-141653-ef2' AND username = 'yacin Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql Wed Feb 6 10:08:10 2013 : Debug: rlm_sql (sql_acct): Reserving sql socket id: 2 Wed Feb 6 10:08:10 2013 : Debug: rlm_sql_mysql: query: UPDATE radacct SET framedipaddress = '10.71.113.16', acctsessiontime = '3', acctinputoctets = '0' << 32 | '1274', acctoutputoctets = '0' << 32 | '9508' WHERE acctsessionid = 'SESS-13815-54b752-141653-ef2' AND username = 'pierre.dupont' AND nasipaddress = '192.168.58.5' Wed Feb 6 10:08:10 2013 : Debug: rlm_sql (sql_acct): Released sql socket id: 2 Wed Feb 6 10:08:10 2013 : Info: ++[sql_acct] returns ok Wed Feb 6 10:08:10 2013 : Info: ++[exec] returns noop Wed Feb 6 10:08:10 2013 : Info: [attr_filter.accounting_response] expand: %{User-Name} -> pierre.dupont Wed Feb 6 10:08:10 2013 : Debug: attr_filter: Matched entry DEFAULT at line 12 Wed Feb 6 10:08:10 2013 : Info: ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 17 to 192.168.58.5 port 20007 Wed Feb 6 10:08:10 2013 : Info: Finished request 227.

2 2

RADIUS authentication using MS-CHAP - no cleartext password configured error
by Deepti kulkarni 06 Feb '13

06 Feb '13

I have a windows client trying to set up L2TP tunnel with my linux router. The linux router talks with the RADIUS server. The authentication is failing because the request is using MS-CHAP and my server cannot handle MS-CHAP. I am not sure what is missing from the configuration on the server. I have the cleartext password in the users file for the "temp" user I am trying to authenticate. Following is the debug output - rad_recv: Access-Request packet from host 10.1.0.33 port 46487, id=142, length=140 Service-Type = Framed-User Framed-Protocol = PPP User-Name = "temp" MS-CHAP-Challenge = 0xa71f9d0753274da79dfe6f0eb2c1b693 MS-CHAP2-Response = 0xea00de5395669cc1880bf8b0020b2b96b4230000000000000000fada537f1a8f3b12453fc739d08219f28644ccfb11ba0225 Calling-Station-Id = "l2tp" NAS-IP-Address = 127.0.1.1 NAS-Port = 0 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] returns ok ++[digest] returns noop [suffix] No '@' in User-Name = "temp", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop [files] users: Matched entry DEFAULT at line 172 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. ++[pap] returns noop Found Auth-Type = MSCHAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group MS-CHAP {...} [mschap] No Cleartext-Password configured. Cannot create LM-Password. [mschap] No Cleartext-Password configured. Cannot create NT-Password. [mschap] Creating challenge hash with username: temp [mschap] Told to do MS-CHAPv2 for temp with NT-Password [mschap] FAILED: No NT/LM-Password. Cannot perform authentication. [mschap] FAILED: MS-CHAP2-Response is incorrect ++[mschap] returns reject Failed to authenticate the user. Login incorrect: [temp] (from client temp-radius port 0 cli l2tp) Using Post-Auth-Type Reject # Executing group from file /etc/freeradius/sites-enabled/default +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> temp attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 4 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 4 Sending Access-Reject of id 142 to 10.1.0.33 port 46487 Waking up in 4.9 seconds. Cleaning up request 4 ID 142 with timestamp +1310 Ready to process requests.

2 1

"Usefull values" from documentation are hardcoded
by Dario Šafar 06 Feb '13

06 Feb '13

Hi, I'm using the latest freeradius2.2.0 built from source. I have one simple question about "Useful values" that are given in documentation of freeradius proxy.conf file. Especially ones considering alive/zombie/dead times. I was trying to set up server to have 1 second revive_interval but to my surprise it was always 60 secs. Then I checked the source code and in realms.c file I've found: if (home->revive_interval < 60) home->revive_interval = 60; if (home->revive_interval > 3600) home->revive_interval = 3600; So the "Useful values" aren't really useful but mandatory values. Is it possible these restrictions would be removed? It would allow the user to set revive_interval (or any other variable value) to 1 sec if he chooses, without the need to build from edited source every time new version of freeradius is released. Best regards, Dario

2 1

session management
by Suresh Kumar Subramanian 06 Feb '13

06 Feb '13

Hi, I am newbie and I have couple of questions in the free radius. 1) How do we maintain the session time in free radius? For example, a given user the session time is configured for 1 hour. After 1 hour, radius server should initiate "Session disconnect message" for the user to the NAS. I understand that, Freeradius does support "session disconnect message", but we can achieve this with radclient utility. Ref: http://wiki.freeradius.org/protocol/Disconnect-Messages Here my problem is, how the session timeout is identified to trigger this disconnect message? Please help. 2) where freeradius logs the accounting information? I have not configured the mysql. Does freeradius supports flat file for storing accounting records.? Thanks Suresh.

2 1

FreeRADIUS performance Issue
by QASIM RAO 06 Feb '13

06 Feb '13

Hi, I am performing performance test on may RADIUS server and having a problem in result... i am using java code for sending 100 concrent requests on my RADIUS server in log i got some chunks taking so much time more than 3 seconds and remaing requests are tacking normal time les than 1 minut. i test after redusing no of request... over all time reduces but chucks are still there.. :( and also mysql is establishing too many connection arround 60 to 70 connections... :( Please help me in this.. Regards: Rao Qasim

2 1

Re: Degradation of service when authentication fails with Windows AD
by Antonio Alberola 06 Feb '13

06 Feb '13

Hi, >> I'm having random authentication failures and I think they are due to >> a Radius server internal failure. I use Radius for authenticating the >> email of users in Windows Active Directory via PAM. Before I used NTLM >> and Kerberos together, and now I use PAM. > > This is confusing. FreeRADIUS is calling the "pam" module, yes? So what is the PAM stack calling? That's correct. I need RADIUS for authenticating POSTFIX users because the authentication depends on the POSTFIX users, via PAM (WINDOWS AD) or UNIX account. I also have many WINDOWS Domain and we need send the credentials to the correct one. > In short: the problem you are experiencing with FreeRADIUS is because > your authentication mechanism (PAM) is taking too long to respond. > This is consuming all threads in the pool, which explains the log messages you see. > > Fix the PAM stack to fail over properly, and this problem will go away. I understand that the PAM mechanism is slow, some domains more than others. But, I don't understand why RADIUS doesn't clean this request with some timeout mechanisms. It's very simple to create a script for crashing the server with a DoS attack. I need a configuration parameter to deny the request if PAM module doesn't respond on time. Why es RADIUS server accepting duplicate requests for queries that have already been sent to it? This is the cause of all threads are busy, correct?

2 1

free radius output attributes configuration
by Lakshmi Narayana Baliah 06 Feb '13

06 Feb '13

Hi All, How can configure output attributes in free-radius? How do i do that ??? please help.... Thanks Lakshmi ============================================================================================================================ Disclaimer: This message and the information contained herein is proprietary and confidential and subject to the Tech Mahindra policy statement, you may review the policy at <a href="http://www.techmahindra.com/Disclaimer.html">http://www.techmahindra.com/Disclaimer.html</a> externally and <a href="http://tim.techmahindra.com/tim/disclaimer.html">http://tim.techmahindra.com/tim/disclaimer.html</a> internally within Tech Mahindra. ============================================================================================================================

3 2

PAM error on reboot of the RADIUS client
by Deepti kulkarni 05 Feb '13

05 Feb '13

Hello, I have a debian machine that acts as RADIUS client talking with the Freeradius server. I have configured PAM on the client, so made following changes. 1 - Added radiusd to /etc/pam.d which contains - @include common-auth @include common-account @include common-password @include common-session 2 - Added following line to /etc/pam.d/common_auth auth sufficient pam_radius_auth.so 3 - Added following line to /etc/pam.d/common_account account required pam_radius_auth.so 4- Added following line to /etc/pam.d/common_session session required pam_radius_auth.so 5 - Added server-ip and secret key to /etc/pam_radius_auth.conf Authentication and accounting works fine after I configure the above on the client. As soon as I reboot client, login fails with error - "cannot make/remove an entry for the specified session". Cannot login into the client. Thanks

2 4