- Freeradius-Users - lists.freeradius.org

users file: =~ and User-Password
by Stefan Winter 24 Mar '06

24 Mar '06

Hi, I'm trying to understand what exactly happens in the users file when processing User-Password. The situation I'm seeing here is in a rather complex scenario, and the results are not quite what I would expect. In short, when a MS-CHAP'ed request comes in and users contains a check User-Password =~ (foo|bar), then even though there is no User-Password attribute in the request itself, it matches. The long story, for those still reading, is: * mySQL database with our "nice" users. Nice means, they have a single password for all of our services (ASMTP, IMAP, VPN, Dial-Up, Groupware). * some users have for ancient reasons two different passwords, one for VPN&Dial-Up, one for the rest. * these users are handled in the users file, with uname User-Password =~ (foo|bar), Auth-Type := Accept * The processing order in authorize and authenticate is: authorize { preprocess nas_auth_log suffix mschap files eap sql } authenticate { Auth-Type MS-CHAP { mschap } eap } Now, -X shows that first authorize->mschap comes into action and sets the Auth-Type to MS-CHAP (fine). It does *NOT* set a User-Password attribute because this can only be retrieved later during authorize->sql. The next module to come is authorize->files. There, in my opinion, the above-mentioned line that contains User-Password =~ (foo|bar) SHOULD NOT match, because there is no User-Password attribute in the request. But: users DOES match (when one of the passwords matches the CHAP challenge) and sets Auth-Type to Accept. This can only mean that files does some auto-validating against the CHAP challenge, where it should only make a simple string comparison (not even that, since the attribute isn't even there, it should just do nothing). Now you could say, so what, the user gets accepted after all, so why do you care? The reason is that as soon as Auth-Type is set to Accept, authenticate->mschap isn't called any more, and so the encryption seeds and and attributes are not set. That way, people end up being accepted by RADIUS, but the VPN concentrator denies access anyways. I'm aware I can get around this by using Auth-Type = Accept, to not override the previously-set MS-CHAP. But the real cause is in that a "users" line matches that, according to the documentation of the =~ operator, shouldn't. If you explain me now that the magic MS-CHAP validation is intentional, no problem: I would even submit a documentation patch explaining things. But just leaving the hand-waiving undocumented is not good IMHO. For complete reference, here's the -X run-through of the case in question (hints line 4 sets a VSA RESTENA-Service-Type to VPN): rad_recv: Access-Request packet from host 158.64.X.Y:1026, id=116, length=152 User-Name = "foobar" NAS-Port = 1801 Service-Type = Framed-User Framed-Protocol = PPP Tunnel-Client-Endpoint:0 = "158.64.A.B" MS-CHAP-Challenge = 0xbla44babcdefb327e8c48eobfuscated MS-CHAP2-Response = 0xwhatever NAS-IP-Address = 158.64.X.Y NAS-Port-Type = Virtual Processing the authorize section of radiusd.conf modcall: entering group authorize for request 30048 hints: Matched DEFAULT at 4 modcall[authorize]: module "preprocess" returns ok for request 30048 radius_xlat: '/var/log/radius/radacct/20060323/VPN-service/auth-detail' rlm_detail: /var/log/radius/radacct/%Y%m%d/%{RESTENA-Service-Type}-service/auth-detail expands to /var/log/radius/radacct/20060323/VPN-service/auth-detail modcall[authorize]: module "nas_auth_log" returns ok for request 30048 rlm_realm: No '@' in User-Name = "foobar", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 30048 rlm_mschap: Found MS-CHAP attributes. Setting 'Auth-Type = MS-CHAP' modcall[authorize]: module "mschap" returns ok for request 30048 users: Matched entry foobar at line 115 modcall[authorize]: module "files" returns ok for request 30048 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 30048 radius_xlat: 'foobar' rlm_sql (sql-normal-vpn): sql_set_user escaped user --> 'foobar' radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE Username = 'foobar' ORDER BY id' rlm_sql (sql-normal-vpn): Reserving sql socket id: 4 radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'foobar' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radreply WHERE Username = 'foobar' ORDER BY id' radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'foobar' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql (sql-normal-vpn): Released sql socket id: 4 modcall[authorize]: module "sql-normal-vpn" returns ok for request 30048 modcall: leaving group authorize (returns ok) for request 30048 rad_check_password: Found Auth-Type Accept rad_check_password: Auth-Type = Accept, accepting the user Login OK: [foobar] (from client moria port 1801) Processing the post-auth section of radiusd.conf modcall: entering group post-auth for request 30048 radius_xlat: '/var/log/radius/radacct/20060323/VPN-service/reply-detail' rlm_detail: /var/log/radius/radacct/%Y%m%d/%{RESTENA-Service-Type}-service/reply-detail expands to /var/log/radius/radacct/20060323/VPN-service/reply-detail modcall[post-auth]: module "nas_reply_log" returns ok for request 30048 rlm_sql (sql-normal-vpn): Processing sql_postauth radius_xlat: 'foobar' rlm_sql (sql-normal-vpn): sql_set_user escaped user --> 'foobar' radius_xlat: 'INSERT into radpostauth (id, user, pass, reply, date) values ('', 'foobar', 'VPN', 'Access-Accept', NOW())' rlm_sql (sql-normal-vpn) in sql_postauth: query is INSERT into radpostauth (id, user, pass, reply, date) values ('', 'foobar', 'VPN', 'Access-Accept', NOW()) rlm_sql (sql-normal-vpn): Reserving sql socket id: 3 rlm_sql (sql-normal-vpn): Released sql socket id: 3 modcall[post-auth]: module "sql-normal-vpn" returns ok for request 30048 modcall: leaving group post-auth (returns ok) for request 30048 Sending Access-Accept of id 116 to 158.64.1.53 port 1026 Finished request 30048 Going to the next request --- Walking the entire request list --- Greetings, Stefan Winter -- Stefan WINTER RESTENA Foundation - Réseau Téléinformatique de l'Education Nationale et de la Recherche R&D Engineer 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg email: stefan.winter(a)restena.lu Tel.: +352 424409-1 http://www.restena.lu Fax: +352 422473

2 3

relams max domains
by Vasco Santos 24 Mar '06

24 Mar '06

Hi again, what is the maximum of domains that I cant put in the realms file of radius clistron version 1.6.4? Tanks

1 0

Proxy domains with multiple @
by Vasco Santos 24 Mar '06

24 Mar '06

Hi I want to proxy domains with multiple @ ex: user@xxxx@zzz.com how I wil put in the proxy.conf? zzz.com or xxxx(a)zzz.com ? Thanks.

1 0

PIX Accounting
by Sergio Sagliocco 24 Mar '06

24 Mar '06

Hello to the list I've configured my PIX 6.3(5) to authenticate PPTP VPN by FreeRadius. I've noticed that if a user login fails, PIX send a STOP Accounting Packet and then a START packet: in this way I have serious problem to track the simultaneous use of the users: I think it is not normal. I know...it is not a problem of freeradius...but maybe somebody of the list had the same problem in the past: do you have some suggestions? Tnx Regards Sergio Sagliocco

2 1

Help me get started
by vignesh 24 Mar '06

24 Mar '06

Hello guys This is Vignesh here. I have just started with Free Radius. I would like to understand the working of Free Radius before I start experimenting with it. We are planning to use Free Radius for developing a telecomm billing solution both prepaid and postpaid. I am not sure where to start from. Could you please help me out with it. If you have any documents, samples and if you can forward It would be of great help. My email id is vignesh(a)novanet.net Thanks in advance Vignesh

1 0

Re: Table radacct is empty
by Vincent MARGUERIE 24 Mar '06

24 Mar '06

freeradius-users-request(a)lists.freeradius.org a écrit : >Send Freeradius-Users mailing list submissions to > freeradius-users(a)lists.freeradius.org > >To subscribe or unsubscribe via the World Wide Web, visit > http://lists.freeradius.org/mailman/listinfo/freeradius-users >or, via email, send a message with subject or body 'help' to > freeradius-users-request(a)lists.freeradius.org > >You can reach the person managing the list at > freeradius-users-owner(a)lists.freeradius.org > >When replying, please edit your Subject line so it is more specific >than "Re: Contents of Freeradius-Users digest..." > > >Today's Topics: > > 1. RE: Table radacct is empty (Vincent MARGUERIE) > 2. RE: Table radacct is empty (Alex M) > > >---------------------------------------------------------------------- > >Message: 1 >Date: Thu, 23 Mar 2006 01:57:27 +0100 >From: Vincent MARGUERIE <vi.marguerie(a)wanadoo.fr> >Subject: RE: Table radacct is empty >To: freeradius <freeradius-users(a)lists.freeradius.org> >Message-ID: <4421F277.7080907(a)wanadoo.fr> >Content-Type: text/plain; charset=ISO-8859-1; format=flowed > >Hi, > >Yes, SQL is ok to query in accounting section. Here is a part of my radiusd.conf : > ># The rlm_sql_log module appends the SQL queries in a log > # file which is read later by the radsqlrelay program. > # > # This module only performs the dynamic expansion of the > # variables found in the SQL statements. No operation is > # executed on the database server. (this could be done > # later by an external program) That means the module is > # useful only with non-"SELECT" statements. > # > # See rlm_sql_log(5) manpage. > # > sql_log { > path = ${radacctdir}/sql-relay > acct_table = "radacct" > postauth_table = "radpostauth" > > Start = "INSERT INTO ${acct_table} (AcctSessionId, UserName, \ > NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, \ > AcctSessionTime, AcctTerminateCause) VALUES \ > ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', \ > '%{Framed-IP-Address}', '%S', '0', '0', '');" > Stop = "INSERT INTO ${acct_table} (AcctSessionId, UserName, \ > NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, \ > AcctSessionTime, AcctTerminateCause) VALUES \ > ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', \ > '%{Framed-IP-Address}', '0', '%S', '%{Acct-Session-Time}', \ > '%{Acct-Terminate-Cause}');" > Alive = "INSERT INTO ${acct_table} (AcctSessionId, UserName, \ > NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, \ > AcctSessionTime, AcctTerminateCause) VALUES \ > ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', \ > '%{Framed-IP-Address}', '0', '0', '%{Acct-Session-Time}','');" > > Post-Auth = "INSERT INTO ${postauth_table} \ > (user, pass, reply, date) VALUES \ > ('%{User-Name}', '%{User-Password:-Chap-Password}', \ > '%{reply:Packet-Type}', '%S');" > } > >...... >...... >$INCLUDE ${confdir}/sql.conf >...... >...... >authorize { > > sql >... >... >accounting { > sql > sql_log >.... >.... >session > sql >.... >.... >post-auth { > sql > sql_log >.... >.... > > >Moreover, the information are written in a file (sql-relay) which (is I have understand correctly) is used by the radsqlrelay binary to put the information in database. > >The fact is that for the post-auth part, it works bacause i get all the information of the post authorisation in the "radpostauth" table. But in this sql-relay file, there's only information about post-auth...nothing about accounting !! > >The strange thing is that there's some informations about accounting in others file "auth-detail" and "reply-detail", but not in sql format. > >some lines of the files : > >"sql-relay" > >INSERT INTO radpostauth (user, pass, reply, date) VALUES ('joseph', 'Chap-Password', 'Access-Accept', '2006-03-21 15:28:48'); > >----------------- > >"reply-detail" > >Packet-Type = Access-Accept >Wed Mar 22 18:04:18 2006 > Framed-Protocol = PPP > Framed-IP-Address = 255.255.255.254 > Framed-IP-Netmask = 255.255.255.0 > Framed-MTU = 10000 > Framed-Compression = Van-Jacobson-TCP-IP > Service-Type = Login-User > Session-Timeout = 1000 > Idle-Timeout = 500 > Port-Limit = 10 > Reply-Message = "Bye Mr Joseph !" > MS-MPPE-Recv-Key = 0x315cddbc0724d537fdb446a4fc50756d12cc3b005e452caeafe6e867a8a273da > MS-MPPE-Send-Key = 0x99246dc1071a72f26b069f36cf13c4c865705471f3dbd0dfa1515615affd3004 > EAP-Message = 0x03090004 > Message-Authenticator = 0x00000000000000000000000000000000 > User-Name = "joseph" > >------------------ > >"auth-detail" > >Packet-Type = Access-Request >Wed Mar 22 17:46:52 2006 > User-Name = "joseph" > Framed-MTU = 1400 > NAS-Port-Type = Wireless-802.11 > NAS-Port = 0 > NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" > Calling-Station-Id = "00-12-f0-4f-19-26" > EAP-Message = 0x0201000b016a6f73657068 > NAS-IP-Address = 192.168.0.50 > Message-Authenticator = 0x3796599b7cebc6895c6a57f7444cccfc > Client-IP-Address = 192.168.0.50 >------------------- >Best regards, >Vincent > > >------------------------------ > >Message: 3 >Date: Wed, 22 Mar 2006 09:17:08 -0500 >From: "Alex M" <radiussupport(a)lrcommunications.net> >Subject: RE: Table radacct is empty >To: "'FreeRadius users mailing list'" > <freeradius-users(a)lists.freeradius.org> >Message-ID: <001c01c64dbb$4dc706f0$e102fe0a@Alexm> >Content-Type: text/plain; charset="us-ascii" > >Did u authorize SQL in accounting section? > > > > >-----Original Message----- >From: >freeradius-users-bounces+radiussupport=lrcommunications.net(a)lists.freeradius >.org >[mailto:freeradius-users-bounces+radiussupport=lrcommunications.net@lists.fr >eeradius.org] On Behalf Of Vincent MARGUERIE >Sent: Wednesday, March 22, 2006 4:14 AM >To: freeradius >Subject: Table radacct is empty > >Hi, > >I've installed freeradius 1.1.1 on a Debian Sarge distribution, and the >connection works fine with my wireless windows XP client but I have a >problem to get information into radacct table in my mysql database. > >Does anyone get solution for this ? > >Rq : I use a Dlink-DWL-2000AP+ as Acces Point > >Regards, >Vincent >- >List info/subscribe/unsubscribe? See >http://www.freeradius.org/list/users.html > > > > >------------------------------ > >Message: 2 >Date: Wed, 22 Mar 2006 21:06:44 -0500 >From: "Alex M" <radiussupport(a)lrcommunications.net> >Subject: RE: Table radacct is empty >To: "'FreeRadius users mailing list'" > <freeradius-users(a)lists.freeradius.org> >Message-ID: <003401c64e1e$6f35a590$6500a8c0@Alexm> >Content-Type: text/plain; charset="us-ascii" > >Well, it seams that u have everything.... and if radius starts properly that >should work.. I'm attaching file that works, try it first and then do all >the adjustments u need. It set to do ONLY authentication and accounting.... >it's for v1.1.0 > > >-----Original Message----- >From: >freeradius-users-bounces+radiussupport=lrcommunications.net(a)lists.freeradius >.org >[mailto:freeradius-users-bounces+radiussupport=lrcommunications.net@lists.fr >eeradius.org] On Behalf Of Vincent MARGUERIE >Sent: Wednesday, March 22, 2006 7:57 PM >To: freeradius >Subject: RE: Table radacct is empty > >Hi, > >Yes, SQL is ok to query in accounting section. Here is a part of my >radiusd.conf : > ># The rlm_sql_log module appends the SQL queries in a log > # file which is read later by the radsqlrelay program. > # > # This module only performs the dynamic expansion of the > # variables found in the SQL statements. No operation is > # executed on the database server. (this could be done > # later by an external program) That means the module is > # useful only with non-"SELECT" statements. > # > # See rlm_sql_log(5) manpage. > # > sql_log { > path = ${radacctdir}/sql-relay > acct_table = "radacct" > postauth_table = "radpostauth" > > Start = "INSERT INTO ${acct_table} (AcctSessionId, UserName, >\ > NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, >\ > AcctSessionTime, AcctTerminateCause) VALUES >\ > ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', >\ > '%{Framed-IP-Address}', '%S', '0', '0', '');" > Stop = "INSERT INTO ${acct_table} (AcctSessionId, UserName, >\ > NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, >\ > AcctSessionTime, AcctTerminateCause) VALUES >\ > ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', >\ > '%{Framed-IP-Address}', '0', '%S', '%{Acct-Session-Time}', >\ > '%{Acct-Terminate-Cause}');" > Alive = "INSERT INTO ${acct_table} (AcctSessionId, UserName, >\ > NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, >\ > AcctSessionTime, AcctTerminateCause) VALUES >\ > ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', >\ > '%{Framed-IP-Address}', '0', '0', >'%{Acct-Session-Time}','');" > > Post-Auth = "INSERT INTO ${postauth_table} >\ > (user, pass, reply, date) VALUES >\ > ('%{User-Name}', '%{User-Password:-Chap-Password}', >\ > '%{reply:Packet-Type}', '%S');" > } > >...... >...... >$INCLUDE ${confdir}/sql.conf >...... >...... >authorize { > > sql >... >... >accounting { > sql > sql_log >.... >.... >session > sql >.... >.... >post-auth { > sql > sql_log >.... >.... > > >Moreover, the information are written in a file (sql-relay) which (is I have >understand correctly) is used by the radsqlrelay binary to put the >information in database. > >The fact is that for the post-auth part, it works bacause i get all the >information of the post authorisation in the "radpostauth" table. But in >this sql-relay file, there's only information about post-auth...nothing >about accounting !! > >The strange thing is that there's some informations about accounting in >others file "auth-detail" and "reply-detail", but not in sql format. > >some lines of the files : > >"sql-relay" > >INSERT INTO radpostauth (user, pass, reply, >date) VALUES ('joseph', >'Chap-Password', 'Access-Accept', '2006-03-21 >15:28:48'); > >----------------- > >"reply-detail" > >Packet-Type = Access-Accept >Wed Mar 22 18:04:18 2006 > Framed-Protocol = PPP > Framed-IP-Address = 255.255.255.254 > Framed-IP-Netmask = 255.255.255.0 > Framed-MTU = 10000 > Framed-Compression = Van-Jacobson-TCP-IP > Service-Type = Login-User > Session-Timeout = 1000 > Idle-Timeout = 500 > Port-Limit = 10 > Reply-Message = "Bye Mr Joseph !" > MS-MPPE-Recv-Key = >0x315cddbc0724d537fdb446a4fc50756d12cc3b005e452caeafe6e867a8a273da > MS-MPPE-Send-Key = >0x99246dc1071a72f26b069f36cf13c4c865705471f3dbd0dfa1515615affd3004 > EAP-Message = 0x03090004 > Message-Authenticator = 0x00000000000000000000000000000000 > User-Name = "joseph" > >------------------ > >"auth-detail" > >Packet-Type = Access-Request >Wed Mar 22 17:46:52 2006 > User-Name = "joseph" > Framed-MTU = 1400 > NAS-Port-Type = Wireless-802.11 > NAS-Port = 0 > NAS-Identifier = >"default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000 >\000\000\000\000\000" > Calling-Station-Id = "00-12-f0-4f-19-26" > EAP-Message = 0x0201000b016a6f73657068 > NAS-IP-Address = 192.168.0.50 > Message-Authenticator = 0x3796599b7cebc6895c6a57f7444cccfc > Client-IP-Address = 192.168.0.50 >------------------- >Best regards, >Vincent > > >------------------------------ > >Message: 3 >Date: Wed, 22 Mar 2006 09:17:08 -0500 >From: "Alex M" <radiussupport(a)lrcommunications.net> >Subject: RE: Table radacct is empty >To: "'FreeRadius users mailing list'" > <freeradius-users(a)lists.freeradius.org> >Message-ID: <001c01c64dbb$4dc706f0$e102fe0a@Alexm> >Content-Type: text/plain; charset="us-ascii" > >Did u authorize SQL in accounting section? > > > > >-----Original Message----- >From: >freeradius-users-bounces+radiussupport=lrcommunications.net(a)lists.freeradius >.org >[mailto:freeradius-users-bounces+radiussupport=lrcommunications.net@lists.fr >eeradius.org] On Behalf Of Vincent MARGUERIE >Sent: Wednesday, March 22, 2006 4:14 AM >To: freeradius >Subject: Table radacct is empty > >Hi, > >I've installed freeradius 1.1.1 on a Debian Sarge distribution, and the >connection works fine with my wireless windows XP client but I have a >problem to get information into radacct table in my mysql database. > >Does anyone get solution for this ? > >Rq : I use a Dlink-DWL-2000AP+ as Acces Point > >Regards, >Vincent >- >List info/subscribe/unsubscribe? See >http://www.freeradius.org/list/users.html > > >- >List info/subscribe/unsubscribe? See >http://www.freeradius.org/list/users.html > Starting - reading configuration files ... reread_config: reading radiusd.conf Config: including file: /usr/local/etc/raddb/proxy.conf Config: including file: /usr/local/etc/raddb/clients.conf Config: including file: /usr/local/etc/raddb/snmp.conf Config: including file: /usr/local/etc/raddb/eap.conf Config: including file: /usr/local/etc/raddb/sql.conf main: prefix = "/usr/local" main: localstatedir = "/usr/local/var" main: logdir = "/usr/local/var/log/radius" main: libdir = "/usr/local/lib" main: radacctdir = "/usr/local/var/log/radius/radacct" main: hostname_lookups = no main: max_request_time = 30 main: cleanup_delay = 5 main: max_requests = 1024 main: delete_blocked_requests = 0 main: port = 0 main: allow_core_dumps = no main: log_stripped_names = no main: log_file = "/usr/local/var/log/radius/radius.log" main: log_auth = no main: log_auth_badpass = no main: log_auth_goodpass = no main: pidfile = "/usr/local/var/run/radiusd/radiusd.pid" main: user = "(null)" main: group = "(null)" main: usercollide = no main: lower_user = "no" main: lower_pass = "no" main: nospace_user = "no" main: nospace_pass = "no" main: checkrad = "/usr/local/sbin/checkrad" main: proxy_requests = yes proxy: retry_delay = 5 proxy: retry_count = 3 proxy: synchronous = no proxy: default_fallback = yes proxy: dead_time = 120 proxy: post_proxy_authorize = no proxy: wake_all_if_all_dead = no security: max_attributes = 200 security: reject_delay = 1 security: status_server = no main: debug_level = 0 read_config_files: reading dictionary read_config_files: reading naslist Using deprecated naslist file. Support for this will go away soon. read_config_files: reading clients read_config_files: reading realms radiusd: entering modules setup Module: Library search path is /usr/local/lib Module: Loaded exec exec: wait = yes exec: program = "(null)" exec: input_pairs = "request" exec: output_pairs = "(null)" exec: packet_type = "(null)" rlm_exec: Wait=yes but no output defined. Did you mean output=none? Module: Instantiated exec (exec) Module: Loaded expr Module: Instantiated expr (expr) Module: Loaded PAP pap: encryption_scheme = "crypt" Module: Instantiated pap (pap) Module: Loaded CHAP Module: Instantiated chap (chap) Module: Loaded MS-CHAP mschap: use_mppe = yes mschap: require_encryption = no mschap: require_strong = no mschap: with_ntdomain_hack = no mschap: passwd = "(null)" mschap: authtype = "MS-CHAP" mschap: ntlm_auth = "(null)" Module: Instantiated mschap (mschap) Module: Loaded System unix: cache = no unix: passwd = "(null)" unix: shadow = "(null)" unix: group = "(null)" unix: radwtmp = "/usr/local/var/log/radius/radwtmp" unix: usegroup = no unix: cache_reload = 600 Module: Instantiated unix (unix) Module: Loaded eap eap: default_eap_type = "md5" eap: timer_expire = 60 eap: ignore_unknown_eap_types = no eap: cisco_accounting_username_bug = no rlm_eap: Loaded and initialized type md5 rlm_eap: Loaded and initialized type leap gtc: challenge = "Password: " gtc: auth_type = "PAP" rlm_eap: Loaded and initialized type gtc tls: rsa_key_exchange = no tls: dh_key_exchange = yes tls: rsa_key_length = 512 tls: dh_key_length = 512 tls: verify_depth = 0 tls: CA_path = "(null)" tls: pem_file_type = yes tls: private_key_file = "/usr/local/etc/raddb/certs/cert-srv.pem" tls: certificate_file = "/usr/local/etc/raddb/certs/cert-srv.pem" tls: CA_file = "/usr/local/etc/raddb/certs/demoCA/cacert.pem" tls: private_key_password = "whatever" tls: dh_file = "/usr/local/etc/raddb/certs/dh" tls: random_file = "/usr/local/etc/raddb/certs/random" tls: fragment_size = 1024 tls: include_length = yes tls: check_crl = yes tls: check_cert_cn = "%{User-Name}" rlm_eap_tls: Loading the certificate file as a chain rlm_eap: Loaded and initialized type tls peap: default_eap_type = "mschapv2" peap: copy_request_to_tunnel = no peap: use_tunneled_reply = no peap: proxy_tunneled_request_as_eap = yes rlm_eap: Loaded and initialized type peap mschapv2: with_ntdomain_hack = no rlm_eap: Loaded and initialized type mschapv2 Module: Instantiated eap (eap) Module: Loaded preprocess preprocess: huntgroups = "/usr/local/etc/raddb/huntgroups" preprocess: hints = "/usr/local/etc/raddb/hints" preprocess: with_ascend_hack = no preprocess: ascend_channels_per_line = 23 preprocess: with_ntdomain_hack = no preprocess: with_specialix_jetstream_hack = no preprocess: with_cisco_vsa_hack = no Module: Instantiated preprocess (preprocess) Module: Loaded realm realm: format = "suffix" realm: delimiter = "@" realm: ignore_default = no realm: ignore_null = no Module: Instantiated realm (suffix) Module: Loaded files files: usersfile = "/usr/local/etc/raddb/users" files: acctusersfile = "/usr/local/etc/raddb/acct_users" files: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users" files: compat = "no" Module: Instantiated files (files) Module: Loaded SQL sql: driver = "rlm_sql_mysql" sql: server = "radius" sql: port = "" sql: login = "dialup_admin" sql: password = "dialup_admin" sql: radius_db = "radius" sql: acct_table = "radacct" sql: acct_table2 = "radacct" sql: authcheck_table = "radcheck" sql: authreply_table = "radreply" sql: groupcheck_table = "radgroupcheck" sql: groupreply_table = "radgroupreply" sql: usergroup_table = "usergroup" sql: nas_table = "nas" sql: dict_table = "dictionary" sql: sqltrace = yes sql: sqltracefile = "/usr/local/var/log/radius/sqltrace.sql" sql: readclients = yes sql: deletestalesessions = yes sql: num_sql_socks = 5 sql: sql_user_name = "%{User-Name}" sql: default_user_profile = "" sql: query_on_not_found = yes 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', AcctSessionTime=unix_timestamp('%S') - unix_timestamp(AcctStartTime), AcctTerminateCause='%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}' WHERE AcctSessionTime=0 AND AcctStopTime=0 AND NASIPAddress= '%{NAS-IP-Address}' AND AcctStartTime <= '%S'" sql: accounting_update_query = "UPDATE radacct SET FramedIPAddress = '%{Framed-IP-Address}', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress= '%{NAS-IP-Address}'" sql: accounting_update_query_alt = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S',INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0')" sql: accounting_start_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) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', '0', '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Acct-Delay-Time}', '0')" sql: accounting_start_query_alt = "UPDATE radacct SET AcctStartTime = '%S', AcctStartDelay = '%{Acct-Delay-Time}', ConnectInfo_start = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'" sql: accounting_stop_query = "UPDATE radacct SET AcctStopTime = '%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}', AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}', ConnectInfo_stop = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'" sql: accounting_stop_query_alt = "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) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{Acct-Delay-Time}')" 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 = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0" sql: postauth_table = "radpostauth" sql: postauth_query = "INSERT into radpostauth (id, user, pass, reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW())" sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to dialup_admin@radius:/radius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 rlm_sql_mysql: Starting connect to MySQL server for #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 rlm_sql_mysql: Starting connect to MySQL server for #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 rlm_sql_mysql: Starting connect to MySQL server for #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 rlm_sql_mysql: Starting connect to MySQL server for #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 rlm_sql_mysql: Starting connect to MySQL server for #4 rlm_sql (sql): Connected new DB handle, #4 rlm_sql (sql): - generate_sql_clients rlm_sql (sql): Query: SELECT * FROM nas rlm_sql (sql): Reserving sql socket id: 4 rlm_sql_mysql: query: SELECT * FROM nas rlm_sql (sql): Read entry nasname=radius-network2,shortname=radius-network2,secret=whatever rlm_sql (sql): Adding client 192.168.0.50 (radius-network2) to clients list rlm_sql (sql): Released sql socket id: 4 Module: Instantiated sql (sql) Module: Loaded Acct-Unique-Session-Id acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Module: Instantiated acct_unique (acct_unique) Module: Loaded detail detail: detailfile = "/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" detail: detailperm = 384 detail: dirperm = 493 detail: locking = no Module: Instantiated detail (detail) Module: Loaded radutmp radutmp: filename = "/usr/local/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) Listening on authentication *:1812 Listening on accounting *:1813 Listening on proxy *:1814 Ready to process requests. rad_recv: Access-Request packet from host 192.168.0.50:1812, id=1, length=131 User-Name = "titi" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" Calling-Station-Id = "00-12-f0-4f-19-26" EAP-Message = 0x020100090174697469 NAS-IP-Address = 192.168.0.50 Message-Authenticator = 0x4acb390471995282619dcdb7a134e8fd Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 modcall[authorize]: module "chap" returns noop for request 0 modcall[authorize]: module "mschap" returns noop for request 0 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 0 rlm_eap: EAP packet type response id 1 length 9 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 0 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 0 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 3 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 3 modcall[authorize]: module "sql" returns ok for request 0 modcall: leaving group authorize (returns updated) for request 0 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 0 rlm_eap: EAP Identity rlm_eap: processing type md5 rlm_eap_md5: Issuing Challenge modcall[authenticate]: module "eap" returns handled for request 0 modcall: leaving group authenticate (returns handled) for request 0 Sending Access-Challenge of id 1 to 192.168.0.50 port 1812 Framed-Protocol = PPP Framed-IP-Address = 255.255.255.254 Framed-IP-Netmask = 255.255.255.255 Framed-MTU = 10000 Framed-Compression = Van-Jacobson-TCP-IP Service-Type = Login-User Session-Timeout = 2000 Idle-Timeout = 1500 Port-Limit = 20 Reply-Message = "Hello" EAP-Message = 0x010200160410d2053c96b6d133ed826ffeb60aa824f7 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xcf2ac34dafc556a2c1d96842085c3c4b Finished request 0 Going to the next request --- Walking the entire request list --- Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.0.50:1812, id=2, length=146 User-Name = "titi" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" Calling-Station-Id = "00-12-f0-4f-19-26" EAP-Message = 0x020200060319 State = 0xcf2ac34dafc556a2c1d96842085c3c4b NAS-IP-Address = 192.168.0.50 Message-Authenticator = 0x4659538a5225178c4fa01da6a3da2478 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 1 modcall[authorize]: module "preprocess" returns ok for request 1 modcall[authorize]: module "chap" returns noop for request 1 modcall[authorize]: module "mschap" returns noop for request 1 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 1 rlm_eap: EAP packet type response id 2 length 6 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 1 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 1 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 2 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 2 modcall[authorize]: module "sql" returns ok for request 1 modcall: leaving group authorize (returns updated) for request 1 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 1 rlm_eap: Request found, released from the list rlm_eap: EAP NAK rlm_eap: EAP-NAK asked for EAP-Type/peap rlm_eap: processing type tls rlm_eap_tls: Initiate rlm_eap_tls: Start returned 1 modcall[authenticate]: module "eap" returns handled for request 1 modcall: leaving group authenticate (returns handled) for request 1 Sending Access-Challenge of id 2 to 192.168.0.50 port 1812 Framed-Protocol = PPP Framed-IP-Address = 255.255.255.254 Framed-IP-Netmask = 255.255.255.255 Framed-MTU = 10000 Framed-Compression = Van-Jacobson-TCP-IP Service-Type = Login-User Session-Timeout = 2000 Idle-Timeout = 1500 Port-Limit = 20 Reply-Message = "Hello" EAP-Message = 0x010300061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x4c66a7cec60613bad39dd9b951b41901 Finished request 1 Going to the next request --- Walking the entire request list --- Waking up in 5 seconds... rad_recv: Access-Request packet from host 192.168.0.50:1812, id=3, length=252 User-Name = "titi" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" Calling-Station-Id = "00-12-f0-4f-19-26" EAP-Message = 0x0203007019800000006616030100610100005d03014422d0d98400d1a4895e89df3e332c5da5ff58d4c6f905aacf9ae472862e525320616132233f656dc5398082909be8a4dbc79751ac3d948171685c39493e61c870001600040005000a000900640062000300060013001200630100 State = 0x4c66a7cec60613bad39dd9b951b41901 NAS-IP-Address = 192.168.0.50 Message-Authenticator = 0xc98d18ba317cf760188b762f77ebea7c Processing the authorize section of radiusd.conf modcall: entering group authorize for request 2 modcall[authorize]: module "preprocess" returns ok for request 2 modcall[authorize]: module "chap" returns noop for request 2 modcall[authorize]: module "mschap" returns noop for request 2 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 2 rlm_eap: EAP packet type response id 3 length 112 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 2 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 2 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 1 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 1 modcall[authorize]: module "sql" returns ok for request 2 modcall: leaving group authorize (returns updated) for request 2 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 2 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS rlm_eap_tls: Length Included eaptls_verify returned 11 (other): before/accept initialization TLS_accept: before/accept initialization rlm_eap_tls: <<< TLS 1.0 Handshake [length 0061], ClientHello TLS_accept: SSLv3 read client hello A rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello TLS_accept: SSLv3 write server hello A rlm_eap_tls: >>> TLS 1.0 Handshake [length 02d1], Certificate TLS_accept: SSLv3 write certificate A rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone TLS_accept: SSLv3 write server done A TLS_accept: SSLv3 flush data TLS_accept:error in SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode eaptls_process returned 13 rlm_eap_peap: EAPTLS_HANDLED modcall[authenticate]: module "eap" returns handled for request 2 modcall: leaving group authenticate (returns handled) for request 2 Sending Access-Challenge of id 3 to 192.168.0.50 port 1812 Framed-Protocol = PPP Framed-IP-Address = 255.255.255.254 Framed-IP-Netmask = 255.255.255.255 Framed-MTU = 10000 Framed-Compression = Van-Jacobson-TCP-IP Service-Type = Login-User Session-Timeout = 2000 Idle-Timeout = 1500 Port-Limit = 20 Reply-Message = "Hello" EAP-Message = 0x010403341900160301004a0200004603014422dfe8c8d3d3fbd1c0e4c207a0b9fca95cc8e06a58ed767df0c00acf9ec4a0203fa621b9992ebbacf131b6d2bb5d4d54cf35f70da4a06449a6ec756c01aed32300040016030102d10b0002cd0002ca0002c7308202c33082022ca003020102020102300d06092a864886f70d010104050030819c310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e310f300d060355040b1306726164697573311b301906035504031312436c69656e7420636572746966696361 EAP-Message = 0x74653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d301e170d3036303332313034353232345a170d3037303332313034353232345a308198310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e310f300d060355040b13067261646975733119301706035504031310526f6f74206365727469666963617465311f301d06092a864886f70d0109011610726f6f74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100 EAP-Message = 0xa9655b4ebd87af8da4209ca334a090eeb75a31047598e1a28f0faac05a3cc298546114e46acf4ddceb36d1c8b76bea40e3cef942492ab8a960ab889684c797a1083885c42e50cf412da4c55ae4c61a34341ae1e6ea1fbac43bc93816426c7d3024d74a70a8c165e2711121f7578f1b1ce22f3b52d40413f06aeec6fb308e1fe50203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003818100a7cf35d510a2aa570548b5d840ec30f9b752888e945d55c897fecc66826aaeed502efd143697a5d5a8f4200e3c8e1b75e6711766d1bba8ac44412492cbc8252d005e5a01b2ca9f2ad5f0be79 EAP-Message = 0x1a64677affde7f065a3bba76aad688758b93be645c99cd6372728960f067ccc7a8b1d5c9b66c8f84340dfa2c39a3d45a1795ecbe16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0470212b0741ad01e96b58b18f02a26a Finished request 2 Going to the next request --- Walking the entire request list --- Waking up in 4 seconds... rad_recv: Access-Request packet from host 192.168.0.50:1812, id=4, length=332 User-Name = "titi" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" Calling-Station-Id = "00-12-f0-4f-19-26" EAP-Message = 0x020400c01980000000b616030100861000008200803f47a295a5a0e518e9cf8ff470c17d9021e392ad94f719ba39ed0b68aef973baa4981d2aafbfa32d986bb4e95c7a5a045cf1964e6eb9c5e8173d1ca25cd6ddc96982267db5bc51c9d78b664664d81dd2f3ef89864a2f31c7da164c2dcc24ba76aa41c7c735e81bc7320efbe64fdd088efdba04dd740983b57a64a065c0466dd1140301000101160301002009520729563cf25e20296b00c77ea24e768046b8cf2ae8b2a1c155008acd13a0 State = 0x0470212b0741ad01e96b58b18f02a26a NAS-IP-Address = 192.168.0.50 Message-Authenticator = 0xb91ecbe5dd9848a123ffb214a4bc16f4 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 3 modcall[authorize]: module "preprocess" returns ok for request 3 modcall[authorize]: module "chap" returns noop for request 3 modcall[authorize]: module "mschap" returns noop for request 3 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 3 rlm_eap: EAP packet type response id 4 length 192 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 3 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 3 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 0 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 0 modcall[authorize]: module "sql" returns ok for request 3 modcall: leaving group authorize (returns updated) for request 3 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 3 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS rlm_eap_tls: Length Included eaptls_verify returned 11 rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange TLS_accept: SSLv3 read client key exchange A rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001] rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished TLS_accept: SSLv3 read finished A rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001] TLS_accept: SSLv3 write change cipher spec A rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished TLS_accept: SSLv3 write finished A TLS_accept: SSLv3 flush data (other): SSL negotiation finished successfully SSL Connection Established eaptls_process returned 13 rlm_eap_peap: EAPTLS_HANDLED modcall[authenticate]: module "eap" returns handled for request 3 modcall: leaving group authenticate (returns handled) for request 3 Sending Access-Challenge of id 4 to 192.168.0.50 port 1812 Framed-Protocol = PPP Framed-IP-Address = 255.255.255.254 Framed-IP-Netmask = 255.255.255.255 Framed-MTU = 10000 Framed-Compression = Van-Jacobson-TCP-IP Service-Type = Login-User Session-Timeout = 2000 Idle-Timeout = 1500 Port-Limit = 20 Reply-Message = "Hello" EAP-Message = 0x010500311900140301000101160301002073f5a025d2c4eb23a003185c11e814c7c9ff92a8d990c56a43dd16c42a9f4a49 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xd90eec51a672043707063eb66cc857ee Finished request 3 Going to the next request --- Walking the entire request list --- Waking up in 3 seconds... rad_recv: Access-Request packet from host 192.168.0.50:1812, id=5, length=146 User-Name = "titi" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" Calling-Station-Id = "00-12-f0-4f-19-26" EAP-Message = 0x020500061900 State = 0xd90eec51a672043707063eb66cc857ee NAS-IP-Address = 192.168.0.50 Message-Authenticator = 0xe241afcfbf2e9156c35e5c7fe89c4013 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 4 modcall[authorize]: module "preprocess" returns ok for request 4 modcall[authorize]: module "chap" returns noop for request 4 modcall[authorize]: module "mschap" returns noop for request 4 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 4 rlm_eap: EAP packet type response id 5 length 6 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 4 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 4 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 4 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 4 modcall[authorize]: module "sql" returns ok for request 4 modcall: leaving group authorize (returns updated) for request 4 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 4 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS rlm_eap_tls: Received EAP-TLS ACK message rlm_eap_tls: ack handshake is finished eaptls_verify returned 3 eaptls_process returned 3 rlm_eap_peap: EAPTLS_SUCCESS modcall[authenticate]: module "eap" returns handled for request 4 modcall: leaving group authenticate (returns handled) for request 4 Sending Access-Challenge of id 5 to 192.168.0.50 port 1812 Framed-Protocol = PPP Framed-IP-Address = 255.255.255.254 Framed-IP-Netmask = 255.255.255.255 Framed-MTU = 10000 Framed-Compression = Van-Jacobson-TCP-IP Service-Type = Login-User Session-Timeout = 2000 Idle-Timeout = 1500 Port-Limit = 20 Reply-Message = "Hello" EAP-Message = 0x01060020190017030100150022bdae731ff7ec4c5288f87acb1e9ee6a4e489ba Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0933dc6675f27fa92fa153d50646e9d0 Finished request 4 Going to the next request --- Walking the entire request list --- Waking up in 2 seconds... rad_recv: Access-Request packet from host 192.168.0.50:1812, id=6, length=172 User-Name = "titi" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" Calling-Station-Id = "00-12-f0-4f-19-26" EAP-Message = 0x0206002019001703010015bbdaf6e920a5deb1c3a75994a2af87eee1fd8384c0 State = 0x0933dc6675f27fa92fa153d50646e9d0 NAS-IP-Address = 192.168.0.50 Message-Authenticator = 0xf6b7241a53e71772bf2ecee78e2bab80 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 5 modcall[authorize]: module "preprocess" returns ok for request 5 modcall[authorize]: module "chap" returns noop for request 5 modcall[authorize]: module "mschap" returns noop for request 5 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 5 rlm_eap: EAP packet type response id 6 length 32 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 5 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 5 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 3 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 3 modcall[authorize]: module "sql" returns ok for request 5 modcall: leaving group authorize (returns updated) for request 5 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 5 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS eaptls_verify returned 7 rlm_eap_tls: Done initial handshake eaptls_process returned 7 rlm_eap_peap: EAPTLS_OK rlm_eap_peap: Session established. Decoding tunneled attributes. rlm_eap_peap: Identity - titi rlm_eap_peap: Tunneled data is valid. PEAP: Got tunneled identity of titi PEAP: Setting default EAP type for tunneled EAP session. PEAP: Setting User-Name to titi Processing the authorize section of radiusd.conf modcall: entering group authorize for request 5 modcall[authorize]: module "preprocess" returns ok for request 5 modcall[authorize]: module "chap" returns noop for request 5 modcall[authorize]: module "mschap" returns noop for request 5 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 5 rlm_eap: EAP packet type response id 6 length 9 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 5 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 5 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 2 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 2 modcall[authorize]: module "sql" returns ok for request 5 modcall: leaving group authorize (returns updated) for request 5 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 5 rlm_eap: EAP Identity rlm_eap: processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge modcall[authenticate]: module "eap" returns handled for request 5 modcall: leaving group authenticate (returns handled) for request 5 PEAP: Got tunneled Access-Challenge modcall[authenticate]: module "eap" returns handled for request 5 modcall: leaving group authenticate (returns handled) for request 5 Sending Access-Challenge of id 6 to 192.168.0.50 port 1812 Framed-Protocol = PPP Framed-IP-Address = 255.255.255.254 Framed-IP-Netmask = 255.255.255.255 Framed-MTU = 10000 Framed-Compression = Van-Jacobson-TCP-IP Service-Type = Login-User Session-Timeout = 2000 Idle-Timeout = 1500 Port-Limit = 20 Reply-Message = "Hello" EAP-Message = 0x010700351900170301002aa28f7c09e7ae2db86b8db4c1d31ff9eec78886114755d6ad3b412844ad953fc7135a49e3512c61bba526 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x72359c99e5aafc65fba33754af94740d Finished request 5 Going to the next request --- Walking the entire request list --- Waking up in 1 seconds... rad_recv: Access-Request packet from host 192.168.0.50:1812, id=7, length=226 User-Name = "titi" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" Calling-Station-Id = "00-12-f0-4f-19-26" EAP-Message = 0x020700561900170301004ba6a962d82356c9c9eb7b01a9411259ab27a21a72352ea4667c34780330d3d4691bf564b5d2301832eae8584fc9e9147d39ccf74884084fa1a14f33e44e3601a8a1ca834c493677e4e363d5 State = 0x72359c99e5aafc65fba33754af94740d NAS-IP-Address = 192.168.0.50 Message-Authenticator = 0xefdec221902ad312a80ec9e872e064a9 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 6 modcall[authorize]: module "preprocess" returns ok for request 6 modcall[authorize]: module "chap" returns noop for request 6 modcall[authorize]: module "mschap" returns noop for request 6 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 6 rlm_eap: EAP packet type response id 7 length 86 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 6 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 6 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 1 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 1 modcall[authorize]: module "sql" returns ok for request 6 modcall: leaving group authorize (returns updated) for request 6 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 6 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS eaptls_verify returned 7 rlm_eap_tls: Done initial handshake eaptls_process returned 7 rlm_eap_peap: EAPTLS_OK rlm_eap_peap: Session established. Decoding tunneled attributes. rlm_eap_peap: EAP type mschapv2 rlm_eap_peap: Tunneled data is valid. PEAP: Setting User-Name to titi PEAP: Adding old state with b1 a8 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 6 modcall[authorize]: module "preprocess" returns ok for request 6 modcall[authorize]: module "chap" returns noop for request 6 modcall[authorize]: module "mschap" returns noop for request 6 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 6 rlm_eap: EAP packet type response id 7 length 63 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 6 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 6 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 0 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 0 modcall[authorize]: module "sql" returns ok for request 6 modcall: leaving group authorize (returns updated) for request 6 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 6 rlm_eap: Request found, released from the list rlm_eap: EAP/mschapv2 rlm_eap: processing type mschapv2 Processing the authenticate section of radiusd.conf modcall: entering group MS-CHAP for request 6 rlm_mschap: Told to do MS-CHAPv2 for titi with NT-Password rlm_mschap: adding MS-CHAPv2 MPPE keys modcall[authenticate]: module "mschap" returns ok for request 6 modcall: leaving group MS-CHAP (returns ok) for request 6 MSCHAP Success modcall[authenticate]: module "eap" returns handled for request 6 modcall: leaving group authenticate (returns handled) for request 6 PEAP: Got tunneled Access-Challenge modcall[authenticate]: module "eap" returns handled for request 6 modcall: leaving group authenticate (returns handled) for request 6 Sending Access-Challenge of id 7 to 192.168.0.50 port 1812 Framed-Protocol = PPP Framed-IP-Address = 255.255.255.254 Framed-IP-Netmask = 255.255.255.255 Framed-MTU = 10000 Framed-Compression = Van-Jacobson-TCP-IP Service-Type = Login-User Session-Timeout = 2000 Idle-Timeout = 1500 Port-Limit = 20 Reply-Message = "Hello" EAP-Message = 0x0108004a1900170301003fd6c567e0dbaed2476aee09307456d62c3dac5a2207a593b1bd57f8ccf156d849e25f8ddfba433141540218b25a7084b9d9099c4abea5509cd92d11a33f303b Message-Authenticator = 0x00000000000000000000000000000000 State = 0x01e06dc994c4d6f80d560ad692dec677 Finished request 6 Going to the next request --- Walking the entire request list --- Cleaning up request 0 ID 1 with timestamp 4422dfe6 Waking up in 1 seconds... --- Walking the entire request list --- Cleaning up request 1 ID 2 with timestamp 4422dfe7 Waking up in 1 seconds... rad_recv: Access-Request packet from host 192.168.0.50:1812, id=8, length=169 User-Name = "titi" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" Calling-Station-Id = "00-12-f0-4f-19-26" EAP-Message = 0x0208001d19001703010012a54f50e5b59ccf96b465ac0d2a057173d0ba State = 0x01e06dc994c4d6f80d560ad692dec677 NAS-IP-Address = 192.168.0.50 Message-Authenticator = 0x0e563ace7de06dfba8ac88224d578525 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 7 modcall[authorize]: module "preprocess" returns ok for request 7 modcall[authorize]: module "chap" returns noop for request 7 modcall[authorize]: module "mschap" returns noop for request 7 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 7 rlm_eap: EAP packet type response id 8 length 29 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 7 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 7 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 4 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 4 modcall[authorize]: module "sql" returns ok for request 7 modcall: leaving group authorize (returns updated) for request 7 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 7 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS eaptls_verify returned 7 rlm_eap_tls: Done initial handshake eaptls_process returned 7 rlm_eap_peap: EAPTLS_OK rlm_eap_peap: Session established. Decoding tunneled attributes. rlm_eap_peap: EAP type mschapv2 rlm_eap_peap: Tunneled data is valid. PEAP: Setting User-Name to titi PEAP: Adding old state with 59 bb Processing the authorize section of radiusd.conf modcall: entering group authorize for request 7 modcall[authorize]: module "preprocess" returns ok for request 7 modcall[authorize]: module "chap" returns noop for request 7 modcall[authorize]: module "mschap" returns noop for request 7 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 7 rlm_eap: EAP packet type response id 8 length 6 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 7 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 7 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 3 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 3 modcall[authorize]: module "sql" returns ok for request 7 modcall: leaving group authorize (returns updated) for request 7 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 7 rlm_eap: Request found, released from the list rlm_eap: EAP/mschapv2 rlm_eap: processing type mschapv2 rlm_eap: Freeing handler modcall[authenticate]: module "eap" returns ok for request 7 modcall: leaving group authenticate (returns ok) for request 7 radius_xlat: 'Hello' PEAP: Tunneled authentication was successful. rlm_eap_peap: SUCCESS modcall[authenticate]: module "eap" returns handled for request 7 modcall: leaving group authenticate (returns handled) for request 7 Sending Access-Challenge of id 8 to 192.168.0.50 port 1812 Framed-Protocol = PPP Framed-IP-Address = 255.255.255.254 Framed-IP-Netmask = 255.255.255.255 Framed-MTU = 10000 Framed-Compression = Van-Jacobson-TCP-IP Service-Type = Login-User Session-Timeout = 2000 Idle-Timeout = 1500 Port-Limit = 20 Reply-Message = "Hello" EAP-Message = 0x010900261900170301001bca01f65c15cded79e77b90a0d64ec1df3c609b3f94afc2cbbadfc5 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x27462903f7c1ad221300527c28fb9deb Finished request 7 Going to the next request Cleaning up request 2 ID 3 with timestamp 4422dfe8 Waking up in 1 seconds... rad_recv: Access-Request packet from host 192.168.0.50:1812, id=9, length=178 User-Name = "titi" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 NAS-Port = 0 NAS-Identifier = "default\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000" Calling-Station-Id = "00-12-f0-4f-19-26" EAP-Message = 0x020900261900170301001b766eb84e2e1afd8d6c1786f4af7b85787de3d16b53c7b5edad6ed6 State = 0x27462903f7c1ad221300527c28fb9deb NAS-IP-Address = 192.168.0.50 Message-Authenticator = 0x37a46af4085448d77fe0d05ead84fdcf Processing the authorize section of radiusd.conf modcall: entering group authorize for request 8 modcall[authorize]: module "preprocess" returns ok for request 8 modcall[authorize]: module "chap" returns noop for request 8 modcall[authorize]: module "mschap" returns noop for request 8 rlm_realm: No '@' in User-Name = "titi", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 8 rlm_eap: EAP packet type response id 9 length 38 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 8 users: Matched entry DEFAULT at line 152 modcall[authorize]: module "files" returns ok for request 8 radius_xlat: 'titi' rlm_sql (sql): sql_set_user escaped user --> 'titi' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 2 rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' rlm_sql_mysql: query: SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id' rlm_sql_mysql: query: SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'titi' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql_mysql: query: SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'titi' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id rlm_sql (sql): Released sql socket id: 2 modcall[authorize]: module "sql" returns ok for request 8 modcall: leaving group authorize (returns updated) for request 8 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 8 rlm_eap: Request found, released from the list rlm_eap: EAP/peap rlm_eap: processing type peap rlm_eap_peap: Authenticate rlm_eap_tls: processing TLS eaptls_verify returned 7 rlm_eap_tls: Done initial handshake eaptls_process returned 7 rlm_eap_peap: EAPTLS_OK rlm_eap_peap: Session established. Decoding tunneled attributes. rlm_eap_peap: Received EAP-TLV response. rlm_eap_peap: Tunneled data is valid. rlm_eap_peap: Success rlm_eap: Freeing handler modcall[authenticate]: module "eap" returns ok for request 8 modcall: leaving group authenticate (returns ok) for request 8 radius_xlat: 'Hello' Sending Access-Accept of id 9 to 192.168.0.50 port 1812 Framed-Protocol = PPP Framed-IP-Address = 255.255.255.254 Framed-IP-Netmask = 255.255.255.255 Framed-MTU = 10000 Framed-Compression = Van-Jacobson-TCP-IP Service-Type = Login-User Session-Timeout = 2000 Idle-Timeout = 1500 Port-Limit = 20 Reply-Message = "Hello" MS-MPPE-Recv-Key = 0xeeff609a80c4d478a4513f2271ee0b37aa9d7030a27dec5c4995199ce0989b81 MS-MPPE-Send-Key = 0x2a4e239720826c913d63df62605460ffa182cf74318177499a7369f91e5adbf1 EAP-Message = 0x03090004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "titi" Finished request 8 Going to the next request --- Walking the entire request list --- Waking up in 1 seconds... --- Walking the entire request list --- Cleaning up request 3 ID 4 with timestamp 4422dfe9 Waking up in 1 seconds... --- Walking the entire request list --- Cleaning up request 4 ID 5 with timestamp 4422dfea Waking up in 1 seconds... --- Walking the entire request list --- Cleaning up request 5 ID 6 with timestamp 4422dfeb Waking up in 1 seconds... --- Walking the entire request list --- Cleaning up request 6 ID 7 with timestamp 4422dfec Waking up in 1 seconds... --- Walking the entire request list --- Cleaning up request 7 ID 8 with timestamp 4422dfed Waking up in 1 seconds... --- Walking the entire request list --- Cleaning up request 8 ID 9 with timestamp 4422dfee Nothing to do. Sleeping until we see a request.

2 2

Odd behaviour: with vs without child processes
by Fenn Bailey 24 Mar '06

24 Mar '06

Hi All (warning, big/verbose email below), First of all, quick summary of setup: - Stock Debian Sarge - Clean freeradius 1.1.1 package downloaded yesterday. Built using standard dpkg-buildpackage from source. - Stock config files, with appropriate SQL bits uncommented for freeradius-mysql to work (see bottom of email). So, generally, it works fine - However, I'm experiencing a problem where whenever an Access-Reject is sent, the response is VERY slow (ie: >30 seconds). This happens if it's a formal Access-Reject via radgroupcheck or just wrong password or whatever (anything that would result in an Access-Reject). Access-Accept is instant/perfect, it's only any Access-Reject. And yes, reject_delay is on its standard setting of 1. Now, the bit that baffled me was I couldn't replicate it in debug mode (freeradius -X). At least, until I worked out it only occurs when freeradius is run normally. If you pass the -s flag (Do not spawn child processes), it works perfectly with a 1 second Access-Reject delay; if you set it to spawn child processes, it appears the reject only gets sent when the request times out (or something). See below for full output of a working and non-working example: Run without child processes: --------------Working---------------- /usr/sbin/freeradius -sfxxyz Starting - reading configuration files ... reread_config: reading radiusd.conf Config: including file: /etc/freeradius/proxy.conf Config: including file: /etc/freeradius/clients.conf Config: including file: /etc/freeradius/snmp.conf Config: including file: /etc/freeradius/eap.conf Config: including file: /etc/freeradius/sql.conf main: prefix = "/usr" main: localstatedir = "/var" main: logdir = "/var/log/freeradius" main: libdir = "/usr/lib/freeradius" main: radacctdir = "/var/log/freeradius/radacct" main: hostname_lookups = no main: snmp = no main: max_request_time = 30 main: cleanup_delay = 5 main: max_requests = 1024 main: delete_blocked_requests = 0 main: port = 0 main: allow_core_dumps = no main: log_stripped_names = no main: log_file = "/var/log/freeradius/radius.log" main: log_auth = yes main: log_auth_badpass = yes main: log_auth_goodpass = no main: pidfile = "/var/run/freeradius/freeradius.pid" main: user = "freerad" main: group = "freerad" 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 Using deprecated naslist file. Support for this will go away soon. read_config_files: reading clients read_config_files: reading realms radiusd: entering modules setup Module: Library search path is /usr/lib/freeradius Module: Loaded exec exec: wait = yes exec: program = "(null)" exec: input_pairs = "request" exec: output_pairs = "(null)" exec: packet_type = "(null)" rlm_exec: Wait=yes but no output defined. Did you mean output=none? Module: Instantiated exec (exec) Module: Loaded expr Module: Instantiated expr (expr) Module: Loaded PAP pap: encryption_scheme = "clear" Module: Instantiated pap (pap) Module: Loaded CHAP Module: Instantiated chap (chap) Module: Loaded MS-CHAP mschap: use_mppe = yes mschap: require_encryption = no mschap: require_strong = no mschap: with_ntdomain_hack = no mschap: passwd = "(null)" mschap: authtype = "MS-CHAP" mschap: ntlm_auth = "(null)" Module: Instantiated mschap (mschap) 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/freeradius/huntgroups" preprocess: hints = "/etc/freeradius/hints" preprocess: with_ascend_hack = no preprocess: ascend_channels_per_line = 23 preprocess: with_ntdomain_hack = no preprocess: with_specialix_jetstream_hack = no preprocess: with_cisco_vsa_hack = no Module: Instantiated preprocess (preprocess) Module: Loaded realm realm: format = "suffix" realm: delimiter = "@" realm: ignore_default = no realm: ignore_null = no Module: Instantiated realm (suffix) Module: Loaded SQL sql: driver = "rlm_sql_mysql" sql: server = "localhost" sql: port = "" sql: login = "freeradius" sql: password = "xxxxxx" sql: radius_db = "freeradius" sql: acct_table = "radacct" sql: acct_table2 = "radacct" sql: authcheck_table = "radcheck" sql: authreply_table = "radreply" sql: groupcheck_table = "radgroupcheck" sql: groupreply_table = "radgroupreply" sql: usergroup_table = "usergroup" sql: nas_table = "nas" sql: dict_table = "dictionary" sql: sqltrace = no sql: sqltracefile = "/var/log/freeradius/sqltrace.sql" sql: readclients = yes 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,radgroupche ck.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,radgrouprep ly.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', AcctSessionTime=unix_timestamp('%S') - unix_timestamp(AcctStartTime), AcctTerminateCause='%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}' WHERE AcctSessionTime=0 AND AcctStopTime=0 AND NASIPAddress= '%{NAS-IP-Address}' AND AcctStartTime <= '%S'" sql: accounting_update_query = "UPDATE radacct SET FramedIPAddress = '%{Framed-IP-Address}', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress= '%{NAS-IP-Address}'" sql: accounting_update_query_alt = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S',INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0')" sql: accounting_start_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) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', '0', '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Acct-Delay-Time}', '0')" sql: accounting_start_query_alt = "UPDATE radacct SET AcctStartTime = '%S', AcctStartDelay = '%{Acct-Delay-Time}', ConnectInfo_start = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'" sql: accounting_stop_query = "UPDATE radacct SET AcctStopTime = '%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}', AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}', ConnectInfo_stop = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'" sql: accounting_stop_query_alt = "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) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{Acct-Delay-Time}')" sql: group_membership_query = "SELECT GroupName FROM usergroup WHERE UserName='%{SQL-User-Name}'" sql: connect_failure_retry_delay = 60 sql: simul_count_query = "SELECT COUNT(*) FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0" sql: simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0" sql: postauth_table = "radpostauth" sql: postauth_query = "INSERT into radpostauth (id, user, pass, reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW())" sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to freeradius@localhost:/freeradius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 rlm_sql_mysql: Starting connect to MySQL server for #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 rlm_sql_mysql: Starting connect to MySQL server for #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 rlm_sql_mysql: Starting connect to MySQL server for #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 rlm_sql_mysql: Starting connect to MySQL server for #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 rlm_sql_mysql: Starting connect to MySQL server for #4 rlm_sql (sql): Connected new DB handle, #4 rlm_sql (sql): - generate_sql_clients rlm_sql (sql): Query: SELECT * FROM nas rlm_sql (sql): Reserving sql socket id: 4 rlm_sql (sql): Read entry nasname=office.xxxx.com.au,shortname=office-nas,secret=xxxxxx rlm_sql (sql): Adding client 218.xxx.xxx.xxx (office-nas) to clients list rlm_sql (sql): Released sql socket id: 4 Module: Instantiated sql (sql) 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 files files: usersfile = "/etc/freeradius/users" files: acctusersfile = "/etc/freeradius/acct_users" files: preproxy_usersfile = "/etc/freeradius/preproxy_users" files: compat = "no" Module: Instantiated files (files) Module: Loaded detail detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" detail: detailperm = 384 detail: dirperm = 493 detail: locking = no Module: Instantiated detail (detail) Module: Loaded System unix: cache = no unix: passwd = "(null)" unix: shadow = "/etc/shadow" unix: group = "(null)" unix: radwtmp = "/var/log/freeradius/radwtmp" unix: usegroup = no unix: cache_reload = 600 Module: Instantiated unix (unix) Module: Loaded radutmp radutmp: filename = "/var/log/freeradius/radutmp" radutmp: username = "%{User-Name}" radutmp: case_sensitive = yes radutmp: check_with_nas = yes radutmp: perm = 384 radutmp: callerid = yes Module: Instantiated radutmp (radutmp) Listening on authentication *:1812 Listening on accounting *:1813 Ready to process requests. rad_recv: Access-Request packet from host 218.xxx.xxx.xxx:2011, id=102, length=69 User-Name = "johnsmith(a)xxxx.com.au" User-Password = "xxxxxx" Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 modcall[authorize]: module "chap" returns noop for request 0 modcall[authorize]: module "mschap" returns noop for request 0 rlm_realm: Looking up realm "xxxx.com.au" for User-Name = "johnsmith(a)xxxx.com.au" rlm_realm: No such realm "xxxx.com.au" modcall[authorize]: module "suffix" returns noop for request 0 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 0 radius_xlat: 'johnsmith(a)xxxx.com.au' rlm_sql (sql): sql_set_user escaped user --> 'johnsmith(a)xxxx.com.au' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'johnsmith(a)xxxx.com.au' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 3 radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupche ck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'johnsmith(a)xxxx.com.au' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'johnsmith(a)xxxx.com.au' ORDER BY id' radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgrouprep ly.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'johnsmith(a)xxxx.com.au' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql (sql): Released sql socket id: 3 modcall[authorize]: module "sql" returns ok for request 0 modcall: leaving group authorize (returns ok) for request 0 rad_check_password: Found Auth-Type Reject rad_check_password: Auth-Type = Reject, rejecting user auth: Failed to validate the user. Login incorrect: [johnsmith(a)xxxx.com.au/xxxxxx] (from client office-nas port 0) Delaying request 0 for 1 seconds Finished request 0 Going to the next request --- Walking the entire request list --- Waking up in 1 seconds... --- Walking the entire request list --- Waking up in 1 seconds... --- Walking the entire request list --- Sending Access-Reject of id 102 to 218.xxx.xxx.xxx port 2011 Reply-Message := "Account Suspended" Waking up in 4 seconds... ------------------------------------- Run WITH child processes: --------------Broken----------------- /usr/sbin/freeradius -fxxyz Starting - reading configuration files ... reread_config: reading radiusd.conf Config: including file: /etc/freeradius/proxy.conf Config: including file: /etc/freeradius/clients.conf Config: including file: /etc/freeradius/snmp.conf Config: including file: /etc/freeradius/eap.conf Config: including file: /etc/freeradius/sql.conf main: prefix = "/usr" main: localstatedir = "/var" main: logdir = "/var/log/freeradius" main: libdir = "/usr/lib/freeradius" main: radacctdir = "/var/log/freeradius/radacct" main: hostname_lookups = no main: snmp = no main: max_request_time = 30 main: cleanup_delay = 5 main: max_requests = 1024 main: delete_blocked_requests = 0 main: port = 0 main: allow_core_dumps = no main: log_stripped_names = no main: log_file = "/var/log/freeradius/radius.log" main: log_auth = yes main: log_auth_badpass = yes main: log_auth_goodpass = no main: pidfile = "/var/run/freeradius/freeradius.pid" main: user = "freerad" main: group = "freerad" 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 Using deprecated naslist file. Support for this will go away soon. read_config_files: reading clients read_config_files: reading realms radiusd: entering modules setup Module: Library search path is /usr/lib/freeradius Module: Loaded exec exec: wait = yes exec: program = "(null)" exec: input_pairs = "request" exec: output_pairs = "(null)" exec: packet_type = "(null)" rlm_exec: Wait=yes but no output defined. Did you mean output=none? Module: Instantiated exec (exec) Module: Loaded expr Module: Instantiated expr (expr) Module: Loaded PAP pap: encryption_scheme = "clear" Module: Instantiated pap (pap) Module: Loaded CHAP Module: Instantiated chap (chap) Module: Loaded MS-CHAP mschap: use_mppe = yes mschap: require_encryption = no mschap: require_strong = no mschap: with_ntdomain_hack = no mschap: passwd = "(null)" mschap: authtype = "MS-CHAP" mschap: ntlm_auth = "(null)" Module: Instantiated mschap (mschap) 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/freeradius/huntgroups" preprocess: hints = "/etc/freeradius/hints" preprocess: with_ascend_hack = no preprocess: ascend_channels_per_line = 23 preprocess: with_ntdomain_hack = no preprocess: with_specialix_jetstream_hack = no preprocess: with_cisco_vsa_hack = no Module: Instantiated preprocess (preprocess) Module: Loaded realm realm: format = "suffix" realm: delimiter = "@" realm: ignore_default = no realm: ignore_null = no Module: Instantiated realm (suffix) Module: Loaded SQL sql: driver = "rlm_sql_mysql" sql: server = "localhost" sql: port = "" sql: login = "freeradius" sql: password = "xxxxxx" sql: radius_db = "freeradius" sql: acct_table = "radacct" sql: acct_table2 = "radacct" sql: authcheck_table = "radcheck" sql: authreply_table = "radreply" sql: groupcheck_table = "radgroupcheck" sql: groupreply_table = "radgroupreply" sql: usergroup_table = "usergroup" sql: nas_table = "nas" sql: dict_table = "dictionary" sql: sqltrace = no sql: sqltracefile = "/var/log/freeradius/sqltrace.sql" sql: readclients = yes 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,radgroupche ck.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,radgrouprep ly.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', AcctSessionTime=unix_timestamp('%S') - unix_timestamp(AcctStartTime), AcctTerminateCause='%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}' WHERE AcctSessionTime=0 AND AcctStopTime=0 AND NASIPAddress= '%{NAS-IP-Address}' AND AcctStartTime <= '%S'" sql: accounting_update_query = "UPDATE radacct SET FramedIPAddress = '%{Framed-IP-Address}', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress= '%{NAS-IP-Address}'" sql: accounting_update_query_alt = "INSERT into radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S',INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0')" sql: accounting_start_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) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', '0', '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Acct-Delay-Time}', '0')" sql: accounting_start_query_alt = "UPDATE radacct SET AcctStartTime = '%S', AcctStartDelay = '%{Acct-Delay-Time}', ConnectInfo_start = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'" sql: accounting_stop_query = "UPDATE radacct SET AcctStopTime = '%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}', AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}', ConnectInfo_stop = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'" sql: accounting_stop_query_alt = "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) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{Acct-Session-Time:-0} + %{Acct-Delay-Time:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{Acct-Input-Octets}', '%{Acct-Output-Octets}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{Acct-Delay-Time}')" sql: group_membership_query = "SELECT GroupName FROM usergroup WHERE UserName='%{SQL-User-Name}'" sql: connect_failure_retry_delay = 60 sql: simul_count_query = "SELECT COUNT(*) FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0" sql: simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0" sql: postauth_table = "radpostauth" sql: postauth_query = "INSERT into radpostauth (id, user, pass, reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW())" sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to freeradius@localhost:/freeradius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 rlm_sql_mysql: Starting connect to MySQL server for #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 rlm_sql_mysql: Starting connect to MySQL server for #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 rlm_sql_mysql: Starting connect to MySQL server for #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 rlm_sql_mysql: Starting connect to MySQL server for #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 rlm_sql_mysql: Starting connect to MySQL server for #4 rlm_sql (sql): Connected new DB handle, #4 rlm_sql (sql): - generate_sql_clients rlm_sql (sql): Query: SELECT * FROM nas rlm_sql (sql): Reserving sql socket id: 4 rlm_sql (sql): Read entry nasname=office.xxxx.com.au,shortname=office-nas,secret=xxxxxx rlm_sql (sql): Adding client 218.xxx.xxx.xxx (office-nas) to clients list rlm_sql (sql): Released sql socket id: 4 Module: Instantiated sql (sql) 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 files files: usersfile = "/etc/freeradius/users" files: acctusersfile = "/etc/freeradius/acct_users" files: preproxy_usersfile = "/etc/freeradius/preproxy_users" files: compat = "no" Module: Instantiated files (files) Module: Loaded detail detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" detail: detailperm = 384 detail: dirperm = 493 detail: locking = no Module: Instantiated detail (detail) Module: Loaded System unix: cache = no unix: passwd = "(null)" unix: shadow = "/etc/shadow" unix: group = "(null)" unix: radwtmp = "/var/log/freeradius/radwtmp" unix: usegroup = no unix: cache_reload = 600 Module: Instantiated unix (unix) Module: Loaded radutmp radutmp: filename = "/var/log/freeradius/radutmp" radutmp: username = "%{User-Name}" radutmp: case_sensitive = yes radutmp: check_with_nas = yes radutmp: perm = 384 radutmp: callerid = yes Module: Instantiated radutmp (radutmp) 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 spawned new child 1. Total threads in pool: 1 Thread spawned new child 2. Total threads in pool: 2 Thread spawned new child 3. Total threads in pool: 3 Thread spawned new child 4. Total threads in pool: 4 Thread spawned new child 5. Total threads in pool: 5 Thread pool initialized Listening on authentication *:1812 Listening on accounting *:1813 Ready to process requests. Thread 1 waiting to be assigned a request Thread 2 waiting to be assigned a request Thread 3 waiting to be assigned a request Thread 4 waiting to be assigned a request Thread 5 waiting to be assigned a request rad_recv: Access-Request packet from host 218.xxx.xxx.xxx:2006, id=101, length=69 --- Walking the entire request list --- Waking up in 31 seconds... Threads: total/active/spare threads = 5/0/5 Thread 1 got semaphore Thread 1 handling request 0, (1 handled so far) User-Name = "johnsmith(a)xxxx.com.au" User-Password = "xxxxxx" Processing the authorize section of radiusd.conf modcall: entering group authorize for request 0 modcall[authorize]: module "preprocess" returns ok for request 0 modcall[authorize]: module "chap" returns noop for request 0 modcall[authorize]: module "mschap" returns noop for request 0 rlm_realm: Looking up realm "xxxx.com.au" for User-Name = "johnsmith(a)xxxx.com.au" rlm_realm: No such realm "xxxx.com.au" modcall[authorize]: module "suffix" returns noop for request 0 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 0 radius_xlat: 'johnsmith(a)xxxx.com.au' rlm_sql (sql): sql_set_user escaped user --> 'johnsmith(a)xxxx.com.au' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'johnsmith(a)xxxx.com.au' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 3 radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupche ck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'johnsmith(a)xxxx.com.au' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'johnsmith(a)xxxx.com.au' ORDER BY id' radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgrouprep ly.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'johnsmith(a)xxxx.com.au' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql (sql): Released sql socket id: 3 modcall[authorize]: module "sql" returns ok for request 0 modcall: leaving group authorize (returns ok) for request 0 rad_check_password: Found Auth-Type Reject rad_check_password: Auth-Type = Reject, rejecting user auth: Failed to validate the user. Login incorrect: [johnsmith(a)xxxx.com.au/xxxxxx] (from client office-nas port 0) Delaying request 0 for 1 seconds Finished request 0 Going to the next request Thread 1 waiting to be assigned a request <<Nothing happens for ~30 seconds here>> --- Walking the entire request list --- Sending Access-Reject of id 101 to 218.xxx.xxx.xxx port 2006 Reply-Message := "Account Suspended" Cleaning up request 0 ID 101 with timestamp 442253f9 Nothing to do. Sleeping until we see a request. ------------------------------------- -----------------Config-------------- cat /etc/freeradius/radiusd.conf | grep -v '#' prefix = /usr exec_prefix = /usr sysconfdir = /etc localstatedir = /var sbindir = ${exec_prefix}/sbin logdir = /var/log/freeradius raddbdir = /etc/freeradius radacctdir = ${logdir}/radacct confdir = ${raddbdir} run_dir = ${localstatedir}/run/freeradius log_file = ${logdir}/radius.log libdir = /usr/lib/freeradius pidfile = ${run_dir}/freeradius.pid user = freerad group = freerad max_request_time = 30 delete_blocked_requests = no cleanup_delay = 5 max_requests = 1024 bind_address = * port = 0 hostname_lookups = no allow_core_dumps = no regular_expressions = yes extended_expressions = yes log_stripped_names = no log_auth = yes log_auth_badpass = yes log_auth_goodpass = no usercollide = no lower_user = no lower_pass = no nospace_user = no nospace_pass = no checkrad = ${sbindir}/checkrad security { max_attributes = 200 reject_delay = 1 status_server = no } proxy_requests = yes $INCLUDE ${confdir}/proxy.conf $INCLUDE ${confdir}/clients.conf snmp = no $INCLUDE ${confdir}/snmp.conf thread pool { start_servers = 5 max_servers = 32 min_spare_servers = 3 max_spare_servers = 10 max_requests_per_server = 0 } modules { pap { encryption_scheme = clear } chap { authtype = CHAP } pam { pam_auth = radiusd } unix { cache = no cache_reload = 600 shadow = /etc/shadow radwtmp = ${logdir}/radwtmp } $INCLUDE ${confdir}/eap.conf mschap { authtype = MS-CHAP } ldap { server = "ldap.your.domain" basedn = "o=My Org,c=UA" filter = "(uid=%{Stripped-User-Name:-%{User-Name}})" start_tls = no access_attr = "dialupAccess" dictionary_mapping = ${raddbdir}/ldap.attrmap ldap_connections_number = 5 timeout = 4 timelimit = 3 net_timeout = 1 } realm IPASS { format = prefix delimiter = "/" ignore_default = no ignore_null = no } realm suffix { format = suffix delimiter = "@" ignore_default = no ignore_null = no } realm realmpercent { format = suffix delimiter = "%" ignore_default = no ignore_null = no } realm ntdomain { format = prefix delimiter = "\\" ignore_default = no ignore_null = no } checkval { item-name = Calling-Station-Id check-name = Calling-Station-Id data-type = string } preprocess { huntgroups = ${confdir}/huntgroups hints = ${confdir}/hints with_ascend_hack = no ascend_channels_per_line = 23 with_ntdomain_hack = no with_specialix_jetstream_hack = no with_cisco_vsa_hack = no } files { usersfile = ${confdir}/users acctusersfile = ${confdir}/acct_users preproxy_usersfile = ${confdir}/preproxy_users compat = no } detail { detailfile = ${radacctdir}/%{Client-IP-Address}/detail-%Y%m%d detailperm = 0600 } acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" } $INCLUDE ${confdir}/sql.conf radutmp { filename = ${logdir}/radutmp username = %{User-Name} case_sensitive = yes check_with_nas = yes perm = 0600 callerid = "yes" } radutmp sradutmp { filename = ${logdir}/sradutmp perm = 0644 callerid = "no" } attr_filter { attrsfile = ${confdir}/attrs } counter daily { filename = ${raddbdir}/db.daily key = User-Name count-attribute = Acct-Session-Time reset = daily counter-name = Daily-Session-Time check-name = Max-Daily-Session allowed-servicetype = Framed-User cache-size = 5000 } sqlcounter dailycounter { counter-name = Daily-Session-Time check-name = Max-Daily-Session sqlmod-inst = sql key = User-Name reset = daily query = "SELECT SUM(AcctSessionTime - \ GREATEST((%b - UNIX_TIMESTAMP(AcctStartTime)), 0)) \ FROM radacct WHERE UserName='%{%k}' AND \ UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'" } sqlcounter monthlycounter { counter-name = Monthly-Session-Time check-name = Max-Monthly-Session sqlmod-inst = sql key = User-Name reset = monthly query = "SELECT SUM(AcctSessionTime - \ GREATEST((%b - UNIX_TIMESTAMP(AcctStartTime)), 0)) \ FROM radacct WHERE UserName='%{%k}' AND \ UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'" } always fail { rcode = fail } always reject { rcode = reject } always ok { rcode = ok simulcount = 0 mpp = no } expr { } digest { } exec { wait = yes input_pairs = request } exec echo { wait = yes program = "/bin/echo %{User-Name}" input_pairs = request output_pairs = reply } ippool main_pool { range-start = 192.168.1.1 range-stop = 192.168.3.254 netmask = 255.255.255.0 cache-size = 800 session-db = ${raddbdir}/db.ippool ip-index = ${raddbdir}/db.ipindex override = no maximum-timeout = 0 } } instantiate { exec expr } authorize { preprocess chap mschap suffix eap sql } authenticate { Auth-Type PAP { pap } Auth-Type CHAP { chap } Auth-Type MS-CHAP { mschap } eap } preacct { preprocess acct_unique suffix files } accounting { detail unix radutmp sql } session { sql } post-auth { } pre-proxy { } post-proxy { eap } ------------------------------------- Any suggestions/help as to what would be causing this very slow reject time (which breaks most clients as they time out) would be most welcome. Thanks, Fenn.

2 1

Binding to LDAP as user, rather than anonymous bind
by Norman Elton 23 Mar '06

23 Mar '06

I've got wireless equipment that can relay MS-CHAP-v2 requests to my FreeRADIUS box from Windows XP clients. I see the radius box making LDAP requests to the LDAP server (over SSL), binding as the anonymous user, and searching for the target user. So far so good. The problem is, our password information is not kept in LDAP, so there is no attribute to compare against. Our LDAP servers pass the authentication request off to Kerberos. The only way to authenticate via LDAP is to bind as the target user with the target password, rather than an anonymous user. Can FreeRadius extract the password out of the MS-CHAP-v2 request, and use it to bind against LDAP over SSL? I would much rather not have to tackle Kerberos, as it looks much more complicated. Thanks for any help, Norman Elton

2 1

File ATTRS
by José Berenguer 23 Mar '06

23 Mar '06

Hello! In the file attrs I have: domain.es Reply-Message = "RADIUS OK" but it doesn't return me the message. También he probado con: domain.es Packet-Type =* ANY, EAP-Message =* ANY, User-Name =* ANY, Message-Authenticator =* ANY, MS-MPPE-Send-Key =* ANY, MS-MPPE-Recv-Key =* ANY, State =* ANY, Tunnel-Type := VLAN, Tunnel-Medium-Type := IEEE-802, Tunnel-Private-Group-Id := "88" In the two cases it authenticates, but it doesn't return anything. Although this way if it works: DEFAULT Packet-Type =* ANY, EAP-Message =* ANY, User-Name =* ANY, Message-Authenticator =* ANY, MS-MPPE-Send-Key =* ANY, MS-MPPE-Recv-Key =* ANY, State =* ANY, Tunnel-Type := VLAN, Tunnel-Medium-Type := IEEE-802, Tunnel-Private-Group-Id := "88" Which the failure is? Thanks!

2 1

radiusd will NOT parse my certificate
by Don Osburn 23 Mar '06

23 Mar '06

Well, I've searched everywhere, and I can't figure this out. I admit, I'm new to all this. I have built/installed freeradius 1.1.0. My openssl is version 0.9.6b-29. I used the defaults everywhere, (ie ./configure, etc). I created my own CA and my own server and client certificates using openssl. (I do NOT have CA.pl and I'm danged if I can find it...) I've created other certs that I use for email and S/MIME and they work fine. However, when I try to install these radius.pem certs and run radiusd -X, I get the following output; ------------------------------------------------------------------- <snip....> rlm_eap: Loaded and initialized type gtc tls: rsa_key_exchange = no tls: dh_key_exchange = yes tls: rsa_key_length = 512 tls: dh_key_length = 512 tls: verify_depth = 0 tls: CA_path = "(null)" tls: pem_file_type = yes tls: private_key_file = "/usr/local/etc/raddb/certs/ozradiusSRVR-cert.pem" tls: certificate_file = "/usr/local/etc/raddb/certs/ozradiusSRVR-cert.pem" tls: CA_file = "/usr/local/etc/raddb/certs/ozcacert.pem" tls: private_key_password = "whatever" tls: dh_file = "/usr/local/etc/raddb/certs/dh" tls: random_file = "/usr/local/etc/raddb/certs/random" tls: fragment_size = 1024 tls: include_length = yes tls: check_crl = no tls: check_cert_cn = "(null)" rlm_eap_tls: Loading the certificate file as a chain 8760:error:0906D06C:PEM routines:PEM_read_bio:no start line:pem_lib.c:662:Expecting: CERTIFICATE 8760:error:0906D06C:PEM routines:PEM_read_bio:no start line:pem_lib.c:662:Expecting: ANY PRIVATE KEY 8760:error:140B0009:SSL routines:SSL_CTX_use_PrivateKey_file:missing asn1 eos:ssl_rsa.c:707: rlm_eap_tls: Error reading private key file rlm_eap: Failed to initialize type tls radiusd.conf[10]: eap: Module instantiation failed. ------------------------------------------------------------------------------------------- I compared my ozradiusSRVR-cert.pem to the default cert-srv.pem file, and the format is very different, even tho they are both .pem files...... I turned on the default cert-srv.pem file in eap.conf, and of course it works just fine. However, when I point eap.conf to MY .pem certs, I always get that error and I can NOT figure out what to do next. Can anyone help me out here? This is probably a stupid neophyte question, but I really need to get this to work, and I can NOT use the default certs for obvious security reasons. Any help would be appreciated. Regards, Don xoomrox(a)comcast.net

2 1