- Freeradius-Users - lists.freeradius.org

Can FAQ 6.10 please be fixed?
by Jens Dreger 11 Nov '07

11 Nov '07

Hi! It took me a while to figure out that FAQ 6.10: http://wiki.freeradius.org/index.php/FAQ#How_do_I_check_the_configuration_b… is simply no longer true. Checked the source: that option is gone. I really really think that option should be there, though. I know there is a shell script that starts a second server on a different port and waits to see if it starts successfully. But that's also broken since the -p Option doesn't seem to work in all cases: ~> strace -e bind freeradius -X -p 32768 2>&1 | grep port main: port = 1812 listen: port = 0 bind(3, {sa_family=AF_INET, sin_port=htons(1812), <-------------------- sin_addr=inet_addr("130.133.100.66")}, 16) = -1 EADDRINUSE (Address already in use) /etc/freeradius/radiusd.conf[228]: Error binding to port for 130.133.100.66:1812 Also, that approach is somewhat ridiculous considered the importance of the radius server in our case. I tried to change the Wiki entry but apparently I don't have permission to do so. Can someone with write access to the Wiki please remove that entry (or better, add the -C option back to freeradius ;) Thanks, Jens. -- Jens Dreger Freie Universitaet Berlin dreger(a)physik.fu-berlin.de Fachbereich Physik - ZEDV Tel: +49 30 83854774 Arnimallee 14 Fax: +49 30 83855902 14195 Berlin

4 5

help with ldap/checkitem
by Joe Vieira 10 Nov '07

10 Nov '07

Hi, I am having some confusing trouble with an LDAP check item. applicable line from ldap attribute file --- checkItem VPNGroupName clarkuVlan ---- Users file. ############## VPN USER CONFIG ######################## DEFAULT NAS-Port-Type == Virtual, Framed-Protocol == PPP, Autz-Type := VPN Reply-Message = "Welcome %u, to Clark University's network #AUTHORIZED USE ONLY#", Fall-Through = Yes ############# VPN TEST USER CONFIG #################### DEFAULT VPNGroupName == testing CVPN3000-IPSec-Split-Tunneling-Policy = 1, Filter-Id="itsadmin-filter", CVPN3000-DHCP-Network-Scope = "140.232.2.1", CVPN3000-IPSec-Split-Tunnel-List ="itsadmin-routes" debug output ... rlm_ldap: checking if remote access for CLARKU\bjulin is allowed by clarkuVpnAccess rlm_ldap: looking for check items in directory... rlm_ldap: Adding clarkuVlan as VPNGroupName, value testing & op=21 ... Login OK: [CLARKU\\bjulin] (from client vpn port 176) Sending Access-Accept of id 8 to 10.13.13.1 port 1025 Reply-Message = "Welcome CLARKU\\\\bjulin, to Clark University's network #AUTHORIZED USE ONLY#" Framed-MTU = 576 MS-CHAP2-Success = 0xxxxxxxxxxxxxxxxxxxxxxxxx MS-MPPE-Recv-Key = 0xxxxxxxxxxxxxxxxxxxxxxxx MS-MPPE-Send-Key = 0xxxxxxxxxxxxxxxxxxxxxxxx MS-MPPE-Encryption-Policy = 0x00000002 MS-MPPE-Encryption-Types = 0x00000004 ... so i see it set the check item VPNGroupName to testing, but it never matches in the users file, can anyone point to what i am doing wrong? -- Joe Vieira UNIX Systems Administrator Clark University - ITS

4 6

Problem with MD5 Authentication and PAP
by Jonathan Wong 10 Nov '07

10 Nov '07

Hi, I am running Freeradius 1.1.4, MySQL, MD5, and PAP. For some reason, I cannot get authenticated using MD5 and PAP. The logins keep failing, and the logs says that I do not have a password set. When I use crypt and clear as the encryption schemes, I am able to get authenticated. The problem is that I am getting an md5 feed, so I have to use MD5. Can someone please help me figure out what I am doing wrong? Please let me know if other information is needed. Another weird thing is when I have PAP and MD5 set, and I do not have a radgroupcheck entry for my group, I can get authenticated by putting the MD5 Hash as my password. For example, if my MD5 hash was "abcd…", I would have to use "abcd…" as my password, and I would get an access-accept. #######Radiusd.conf######### modules{ pap { encryption_scheme = md5 } } authorize { preprocess auth_log sql } authenticate { Auth-Type PAP { pap } } ####### radcheck table entry ######### +----+----------+-----------+----+----------------------------------+ | id | UserName | Attribute | op | Value | +----+----------+-----------+----+----------------------------------+ | 36 | stryker8 | Password | := | 5f4dcc3b5aa765d61d8327deb882cf99 | +----+----------+-----------+----+----------------------------------+ ####### radreply table entry ######### +----+----------+-----------+----+----------------+ | id | UserName | Attribute | op | Value | +----+----------+-----------+----+----------------+ | 36 | stryker8 | Class | = | OU=utnet-staff | +----+----------+-----------+----+----------------+ ####### radgroupcheck table entry ######### +----+-------------+-----------+----+-------+ | id | GroupName | Attribute | op | Value | +----+-------------+-----------+----+-------+ | 8 | utnet-staff | Auth-Type | := | PAP | +----+-------------+-----------+----+-------+ ####### radiusd –X log ######### rad_recv: Access-Request packet from host 128.83.135.171:3335, id=5, length=48 User-Name = "stryker8" User-Password = "password" Processing the authorize section of radiusd.conf modcall: entering group authorize for request 1 modcall[authorize]: module "preprocess" returns ok for request 1 radius_xlat: '/var/log/radius/radacct/128.83.135.171/auth-detail-20071109' rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/128.83.135.171/auth-detail-20071109 modcall[authorize]: module "auth_log" returns ok for request 1 radius_xlat: 'stryker8' rlm_sql (sql): sql_set_user escaped user --> 'stryker8' radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE Username = 'stryker8' 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 = 'stryker8' ORDER BY id radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'stryker8' 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 = 'stryker8' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radreply WHERE Username = 'stryker8' ORDER BY id' rlm_sql_mysql: query: SELECT id,UserName,Attribute,Value,op FROM radreply WHERE Username = 'stryker8' ORDER BY id radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'stryker8' 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 = 'stryker8' 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 1 rlm_pap: Found existing Auth-Type, not changing it. modcall[authorize]: module "pap" returns noop for request 1 modcall: group authorize returns ok for request 1 rad_check_password: Found Auth-Type PAP auth: type "PAP" Processing the authenticate section of radiusd.conf modcall: entering group Auth-Type for request 1 rlm_pap: login attempt with password password rlm_pap: No password configured for the user. Cannot do authentication modcall[authenticate]: module "pap" returns fail for request 1 modcall: group Auth-Type returns fail for request 1 auth: Failed to validate the user. Login incorrect: [stryker8] (from client JW-Client port 0) -------- Also, since I am running 1.1.4, I tried using the auto-header in PAP, instead of the encryption_scheme. I set auto_header = yes in the pap module in radiusd.conf I set my Attribute to "MD5-Password" in the radcheck table. I added "pap" to the end of the Authorize Module in radiusd.conf I get the following error: radius_xlat: 'SELECT id,UserName,Attribute,Value,op FROM radcheck WHERE Username = 'stryker8' 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 = 'stryker8' ORDER BY id rlm_sql: Failed to create the pair: Unknown attribute "MD5-Password" rlm_sql (sql): Error getting data from database rlm_sql (sql): SQL query error; rejecting user rlm_sql (sql): Released sql socket id: 2 modcall[authorize]: module "sql" returns fail for request 2 modcall: group authorize returns fail for request 2 There was no response configured: rejecting request 2 Server rejecting request 2. Thanks for your help in advance! Jonathan

3 3

Supported oracle versions
by Eurico Giacon 10 Nov '07

10 Nov '07

Hi People, I´m installing freeradius with oracle using RedHat as operating system. Where could I find which are the oracle versions supported by freeradius 1.1.7 ? Could ou please, say me where this type of information is posted (if there is something like this...) Thanks, Eurico.

2 1

reply name defaults to session timeout.
by Graeme Crawford 09 Nov '07

09 Nov '07

hi All, Im playing around with freeradius ldap and mysql, i built a sql counter and the reply-name is chillispot-max-output-octets but when running a radius -X it returns as session-timeout, which obviously screws me around. all the other reply items come back fine, strange. Anyone had the same sort of issues. Thanks, Graeme.

1 0

cant connect with ntradping
by Murilo Bernardes 09 Nov '07

09 Nov '07

Hi, i'm trying to ntradping my radius server but this is what radius log shows Thu Nov 8 14:10:39 2007 : Auth: rlm_unix: [root]: invalid password Thu Nov 8 14:10:39 2007 : Auth: Login incorrect: [root/ \...(:;] (from client testesomente port 0) i understand that this root password is the linux root password from my server, but it keeps saying that this is incorrect. and at the radius.conf i setted port to be 1812 and its saying port 0. this is what freeradius -X shows: main: nospace_user = "no" main: nospace_pass = "no" main: checkrad = "/usr/sbin/checkrad" main: proxy_requests = 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 Using deprecated clients file. Support for this will go away soon. 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 = "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: ntlm_auth = "(null)" Module: Instantiated mschap (mschap) Module: Loaded System unix: cache = no unix: passwd = "/etc/passwd" unix: shadow = "/etc/shadow" unix: group = "/etc/group" unix: radwtmp = "/var/log/freeradius/radwtmp" unix: usegroup = no unix: cache_reload = 600 Module: Instantiated unix (unix) Module: Loaded eap eap: default_eap_type = "md5" eap: timer_expire = 60 eap: ignore_unknown_eap_types = no eap: cisco_accounting_username_bug = no rlm_eap: Loaded and initialized type md5 rlm_eap: Loaded and initialized type leap gtc: challenge = "Password: " gtc: auth_type = "PAP" rlm_eap: Loaded and initialized type gtc mschapv2: with_ntdomain_hack = no rlm_eap: Loaded and initialized type mschapv2 Module: Instantiated eap (eap) Module: Loaded preprocess preprocess: huntgroups = "/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 preprocess: with_alvarion_vsa_hack = no Module: Instantiated preprocess (preprocess) Module: Loaded realm realm: format = "suffix" realm: delimiter = "@" realm: ignore_default = no realm: ignore_null = no Module: Instantiated realm (suffix) Module: Loaded files files: usersfile = "/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 SQL sql: driver = "rlm_sql_mysql" sql: server = "localhost" sql: port = "" sql: login = "root" sql: password = "#s3nh4$r00t%" sql: radius_db = "radius" sql: nas_table = "nas" sql: sqltrace = no sql: sqltracefile = "/var/log/freeradius/sqltrace.sql" sql: readclients = no sql: deletestalesessions = yes sql: num_sql_socks = 5 sql: sql_user_name = "%{User-Name}" sql: default_user_profile = "" sql: query_on_not_found = no sql: authorize_check_query = "SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id" sql: authorize_reply_query = "SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id" sql: authorize_group_check_query = "SELECT radgroupcheck.id, radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value, radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id" sql: authorize_group_reply_query = "SELECT radgroupreply.id, radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value, radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = '%{SQL-User-Name}' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id" sql: accounting_onoff_query = "UPDATE radacct SET AcctStopTime='%S', 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_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 root@localhost:/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 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 = "/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 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. -- -------------------------------------------------------------- Murilo Bernades

2 2

dhcp ttls 3com 7760
by Jouvenel Jean-Pierre 09 Nov '07

09 Nov '07

Hello, I want to use EAP-TTLS with PAP. Authentication seems good but attribute Tunnel-Private-Group-Id:0 = "88" doesn't works and dhcp send me NAS's VLAN default and not VLAN 88. Thanks DEBUG FREERADIUS FreeRADIUS Version 1.1.3, on Debian Fri Nov 9 10:13:47 2007 : Info: Starting - reading configuration files ... Fri Nov 9 10:13:47 2007 : Debug: reread_config: reading radiusd.conf Fri Nov 9 10:13:47 2007 : Debug: Config: including file: /etc/freeradius/proxy.conf Fri Nov 9 10:13:47 2007 : Debug: Config: including file: /etc/freeradius/clients.conf Fri Nov 9 10:13:47 2007 : Debug: Config: including file: /etc/freeradius/snmp.conf Fri Nov 9 10:13:47 2007 : Debug: Config: including file: /etc/freeradius/eap.conf Fri Nov 9 10:13:47 2007 : Debug: Config: including file: /etc/freeradius/sql.conf Fri Nov 9 10:13:47 2007 : Debug: main: prefix = "/usr" Fri Nov 9 10:13:47 2007 : Debug: main: localstatedir = "/var" Fri Nov 9 10:13:47 2007 : Debug: main: logdir = "/var/log/freeradius" Fri Nov 9 10:13:47 2007 : Debug: main: libdir = "/usr/lib/freeradius" Fri Nov 9 10:13:47 2007 : Debug: main: radacctdir = "/var/log/freeradius/radacct" Fri Nov 9 10:13:47 2007 : Debug: main: hostname_lookups = no Fri Nov 9 10:13:47 2007 : Debug: main: max_request_time = 30 Fri Nov 9 10:13:47 2007 : Debug: main: cleanup_delay = 5 Fri Nov 9 10:13:47 2007 : Debug: main: max_requests = 1024 Fri Nov 9 10:13:47 2007 : Debug: main: delete_blocked_requests = 0 Fri Nov 9 10:13:47 2007 : Debug: main: port = 0 Fri Nov 9 10:13:47 2007 : Debug: main: allow_core_dumps = no Fri Nov 9 10:13:47 2007 : Debug: main: log_stripped_names = no Fri Nov 9 10:13:47 2007 : Debug: main: log_file = "/var/log/freeradius/radius.log" Fri Nov 9 10:13:47 2007 : Debug: main: log_auth = no Fri Nov 9 10:13:47 2007 : Debug: main: log_auth_badpass = no Fri Nov 9 10:13:47 2007 : Debug: main: log_auth_goodpass = no Fri Nov 9 10:13:47 2007 : Debug: main: pidfile = "/var/run/freeradius/freeradius.pid" Fri Nov 9 10:13:47 2007 : Debug: main: user = "freerad" Fri Nov 9 10:13:47 2007 : Debug: main: group = "freerad" Fri Nov 9 10:13:47 2007 : Debug: main: usercollide = no Fri Nov 9 10:13:47 2007 : Debug: main: lower_user = "no" Fri Nov 9 10:13:47 2007 : Debug: main: lower_pass = "no" Fri Nov 9 10:13:47 2007 : Debug: main: nospace_user = "no" Fri Nov 9 10:13:47 2007 : Debug: main: nospace_pass = "no" Fri Nov 9 10:13:47 2007 : Debug: main: checkrad = "/usr/sbin/checkrad" Fri Nov 9 10:13:47 2007 : Debug: main: proxy_requests = yes Fri Nov 9 10:13:47 2007 : Debug: proxy: retry_delay = 5 Fri Nov 9 10:13:47 2007 : Debug: proxy: retry_count = 3 Fri Nov 9 10:13:47 2007 : Debug: proxy: synchronous = no Fri Nov 9 10:13:47 2007 : Debug: proxy: default_fallback = yes Fri Nov 9 10:13:47 2007 : Debug: proxy: dead_time = 120 Fri Nov 9 10:13:47 2007 : Debug: proxy: post_proxy_authorize = no Fri Nov 9 10:13:47 2007 : Debug: proxy: wake_all_if_all_dead = no Fri Nov 9 10:13:47 2007 : Debug: security: max_attributes = 200 Fri Nov 9 10:13:47 2007 : Debug: security: reject_delay = 1 Fri Nov 9 10:13:47 2007 : Debug: security: status_server = no Fri Nov 9 10:13:47 2007 : Debug: main: debug_level = 0 Fri Nov 9 10:13:47 2007 : Debug: read_config_files: reading dictionary Fri Nov 9 10:13:47 2007 : Debug: read_config_files: reading naslist Fri Nov 9 10:13:47 2007 : Info: Using deprecated naslist file. Support for this will go away soon. Fri Nov 9 10:13:47 2007 : Debug: read_config_files: reading clients Fri Nov 9 10:13:47 2007 : Debug: read_config_files: reading realms Fri Nov 9 10:13:47 2007 : Debug: radiusd: entering modules setup Fri Nov 9 10:13:47 2007 : Debug: Module: Library search path is /usr/lib/freeradius Fri Nov 9 10:13:47 2007 : Debug: Module: Loaded exec Fri Nov 9 10:13:47 2007 : Debug: exec: wait = yes Fri Nov 9 10:13:47 2007 : Debug: exec: program = "(null)" Fri Nov 9 10:13:47 2007 : Debug: exec: input_pairs = "request" Fri Nov 9 10:13:47 2007 : Debug: exec: output_pairs = "(null)" Fri Nov 9 10:13:47 2007 : Debug: exec: packet_type = "(null)" Fri Nov 9 10:13:47 2007 : Info: rlm_exec: Wait=yes but no output defined. Did you mean output=none? Fri Nov 9 10:13:47 2007 : Debug: Module: Instantiated exec (exec) Fri Nov 9 10:13:47 2007 : Debug: Module: Loaded expr Fri Nov 9 10:13:47 2007 : Debug: Module: Instantiated expr (expr) Fri Nov 9 10:13:47 2007 : Debug: Module: Loaded PAP Fri Nov 9 10:13:47 2007 : Debug: pap: encryption_scheme = "clear" Fri Nov 9 10:13:47 2007 : Debug: Module: Instantiated pap (pap) Fri Nov 9 10:13:47 2007 : Debug: Module: Loaded eap Fri Nov 9 10:13:47 2007 : Debug: eap: default_eap_type = "ttls" Fri Nov 9 10:13:47 2007 : Debug: eap: timer_expire = 60 Fri Nov 9 10:13:47 2007 : Debug: eap: ignore_unknown_eap_types = no Fri Nov 9 10:13:47 2007 : Debug: eap: cisco_accounting_username_bug = no Fri Nov 9 10:13:47 2007 : Debug: gtc: challenge = "Password: " Fri Nov 9 10:13:47 2007 : Debug: gtc: auth_type = "PAP" Fri Nov 9 10:13:47 2007 : Debug: rlm_eap: Loaded and initialized type gtc Fri Nov 9 10:13:47 2007 : Debug: tls: rsa_key_exchange = no Fri Nov 9 10:13:47 2007 : Debug: tls: dh_key_exchange = yes Fri Nov 9 10:13:47 2007 : Debug: tls: rsa_key_length = 512 Fri Nov 9 10:13:47 2007 : Debug: tls: dh_key_length = 512 Fri Nov 9 10:13:47 2007 : Debug: tls: verify_depth = 0 Fri Nov 9 10:13:47 2007 : Debug: tls: CA_path = "(null)" Fri Nov 9 10:13:47 2007 : Debug: tls: pem_file_type = yes Fri Nov 9 10:13:47 2007 : Debug: tls: private_key_file = "/etc/freeradius/certs/root(a)iut-nimes.fr-cert.pem" Fri Nov 9 10:13:47 2007 : Debug: tls: certificate_file = "/etc/freeradius/certs/root(a)iut-nimes.fr-cert.pem" Fri Nov 9 10:13:47 2007 : Debug: tls: CA_file = "/etc/freeradius/certs/racine_radius_ca-cacert.pem" Fri Nov 9 10:13:47 2007 : Debug: tls: private_key_password = "radcert123" Fri Nov 9 10:13:47 2007 : Debug: tls: dh_file = "/etc/freeradius/certs/dh" Fri Nov 9 10:13:47 2007 : Debug: tls: random_file = "/etc/freeradius/certs/random" Fri Nov 9 10:13:47 2007 : Debug: tls: fragment_size = 1024 Fri Nov 9 10:13:47 2007 : Debug: tls: include_length = yes Fri Nov 9 10:13:47 2007 : Debug: tls: check_crl = no Fri Nov 9 10:13:47 2007 : Debug: tls: check_cert_cn = "(null)" Fri Nov 9 10:13:47 2007 : Debug: tls: cipher_list = "(null)" Fri Nov 9 10:13:47 2007 : Debug: tls: check_cert_issuer = "(null)" Fri Nov 9 10:13:47 2007 : Info: rlm_eap_tls: Loading the certificate file as a chain Fri Nov 9 10:13:48 2007 : Debug: rlm_eap: Loaded and initialized type tls Fri Nov 9 10:13:48 2007 : Debug: ttls: default_eap_type = "gtc" Fri Nov 9 10:13:48 2007 : Debug: ttls: copy_request_to_tunnel = yes Fri Nov 9 10:13:48 2007 : Debug: ttls: use_tunneled_reply = yes Fri Nov 9 10:13:48 2007 : Debug: rlm_eap: Loaded and initialized type ttls Fri Nov 9 10:13:48 2007 : Debug: Module: Instantiated eap (eap) Fri Nov 9 10:13:48 2007 : Debug: Module: Loaded files Fri Nov 9 10:13:48 2007 : Debug: files: usersfile = "/etc/freeradius/users" Fri Nov 9 10:13:48 2007 : Debug: files: acctusersfile = "/etc/freeradius/acct_users" Fri Nov 9 10:13:48 2007 : Debug: files: preproxy_usersfile = "/etc/freeradius/preproxy_users" Fri Nov 9 10:13:48 2007 : Debug: files: compat = "no" Fri Nov 9 10:13:48 2007 : Debug: Module: Instantiated files (files) Fri Nov 9 10:13:48 2007 : Debug: Module: Loaded preprocess Fri Nov 9 10:13:48 2007 : Debug: preprocess: huntgroups = "/etc/freeradius/huntgroups" Fri Nov 9 10:13:48 2007 : Debug: preprocess: hints = "/etc/freeradius/hints" Fri Nov 9 10:13:48 2007 : Debug: preprocess: with_ascend_hack = no Fri Nov 9 10:13:48 2007 : Debug: preprocess: ascend_channels_per_line = 23 Fri Nov 9 10:13:48 2007 : Debug: preprocess: with_ntdomain_hack = no Fri Nov 9 10:13:48 2007 : Debug: preprocess: with_specialix_jetstream_hack = no Fri Nov 9 10:13:48 2007 : Debug: preprocess: with_cisco_vsa_hack = no Fri Nov 9 10:13:48 2007 : Debug: preprocess: with_alvarion_vsa_hack = no Fri Nov 9 10:13:48 2007 : Debug: Module: Instantiated preprocess (preprocess) Fri Nov 9 10:13:48 2007 : Debug: Module: Loaded Acct-Unique-Session-Id Fri Nov 9 10:13:48 2007 : Debug: acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Fri Nov 9 10:13:48 2007 : Debug: Module: Instantiated acct_unique (acct_unique) Fri Nov 9 10:13:48 2007 : Debug: Module: Loaded realm Fri Nov 9 10:13:48 2007 : Debug: realm: format = "suffix" Fri Nov 9 10:13:48 2007 : Debug: realm: delimiter = "@" Fri Nov 9 10:13:48 2007 : Debug: realm: ignore_default = no Fri Nov 9 10:13:48 2007 : Debug: realm: ignore_null = no Fri Nov 9 10:13:48 2007 : Debug: Module: Instantiated realm (suffix) Fri Nov 9 10:13:48 2007 : Debug: Module: Loaded detail Fri Nov 9 10:13:48 2007 : Debug: detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Fri Nov 9 10:13:48 2007 : Debug: detail: detailperm = 384 Fri Nov 9 10:13:48 2007 : Debug: detail: dirperm = 493 Fri Nov 9 10:13:48 2007 : Debug: detail: locking = no Fri Nov 9 10:13:48 2007 : Debug: Module: Instantiated detail (detail) Fri Nov 9 10:13:48 2007 : Debug: Module: Loaded System Fri Nov 9 10:13:48 2007 : Debug: unix: cache = no Fri Nov 9 10:13:48 2007 : Debug: unix: passwd = "(null)" Fri Nov 9 10:13:48 2007 : Debug: unix: shadow = "/etc/shadow" Fri Nov 9 10:13:48 2007 : Debug: unix: group = "(null)" Fri Nov 9 10:13:48 2007 : Debug: unix: radwtmp = "/var/log/freeradius/radwtmp" Fri Nov 9 10:13:48 2007 : Debug: unix: usegroup = no Fri Nov 9 10:13:48 2007 : Debug: unix: cache_reload = 600 Fri Nov 9 10:13:48 2007 : Debug: Module: Instantiated unix (unix) Fri Nov 9 10:13:48 2007 : Debug: Module: Loaded radutmp Fri Nov 9 10:13:48 2007 : Debug: radutmp: filename = "/var/log/freeradius/radutmp" Fri Nov 9 10:13:48 2007 : Debug: radutmp: username = "%{User-Name}" Fri Nov 9 10:13:48 2007 : Debug: radutmp: case_sensitive = yes Fri Nov 9 10:13:48 2007 : Debug: radutmp: check_with_nas = yes Fri Nov 9 10:13:48 2007 : Debug: radutmp: perm = 384 Fri Nov 9 10:13:48 2007 : Debug: radutmp: callerid = yes Fri Nov 9 10:13:48 2007 : Debug: Module: Instantiated radutmp (radutmp) Fri Nov 9 10:13:48 2007 : Debug: Listening on authentication *:1812 Fri Nov 9 10:13:48 2007 : Debug: Listening on accounting *:1813 Fri Nov 9 10:13:48 2007 : Info: Ready to process requests. rad_recv: Access-Request packet from host 192.168.2.136:1067, id=27, length=179 Message-Authenticator = 0xc777320292ba053ae8629646e7d286d4 Service-Type = Framed-User User-Name = "test88" Framed-MTU = 1488 Called-Station-Id = "00-18-6E-9A-49-40:eap" Calling-Station-Id = "00-16-6F-42-28-0F" NAS-Identifier = "3comeap" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x021b000b01746573743838 NAS-IP-Address = 192.168.2.136 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Fri Nov 9 10:13:58 2007 : Debug: Processing the authorize section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authorize for request 0 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP packet type response id 27 length 11 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 0 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 0 Fri Nov 9 10:13:58 2007 : Debug: users: Matched entry test88 at line 89 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 0 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "files" returns ok for request 0 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authorize (returns updated) for request 0 Fri Nov 9 10:13:58 2007 : Debug: rad_check_password: Found Auth-Type EAP Fri Nov 9 10:13:58 2007 : Debug: auth: type "EAP" Fri Nov 9 10:13:58 2007 : Debug: Processing the authenticate section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authenticate for request 0 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 0 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP Identity Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: processing type tls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: Initiate Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: Start returned 1 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 0 Fri Nov 9 10:13:58 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 0 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 0 Sending Access-Challenge of id 27 to 192.168.2.136 port 1067 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" EAP-Message = 0x011c00061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xd2177350f1aeca055b21e4b7478c3c29 Fri Nov 9 10:13:58 2007 : Debug: Finished request 0 Fri Nov 9 10:13:58 2007 : Debug: Going to the next request Fri Nov 9 10:13:58 2007 : Debug: --- Walking the entire request list --- Fri Nov 9 10:13:58 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.136:1067, id=28, length=279 Message-Authenticator = 0x6a90c00463c671bc9cf9fff2e3b69fd7 Service-Type = Framed-User User-Name = "test88" Framed-MTU = 1488 State = 0xd2177350f1aeca055b21e4b7478c3c29 Called-Station-Id = "00-18-6E-9A-49-40:eap" Calling-Station-Id = "00-16-6F-42-28-0F" NAS-Identifier = "3comeap" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x021c005d150016030100520100004e0301473425793d9577ad5304cc664c14ffb9bbcf523d0f0ed0936a3610bf1848800000002600390038003500160013000a00330032002f0005000400150012000900140011000800060003020100 NAS-IP-Address = 192.168.2.136 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Fri Nov 9 10:13:58 2007 : Debug: Processing the authorize section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authorize for request 1 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 1 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP packet type response id 28 length 93 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 1 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 1 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 1 Fri Nov 9 10:13:58 2007 : Debug: users: Matched entry test88 at line 89 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 1 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "files" returns ok for request 1 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authorize (returns updated) for request 1 Fri Nov 9 10:13:58 2007 : Debug: rad_check_password: Found Auth-Type EAP Fri Nov 9 10:13:58 2007 : Debug: auth: type "EAP" Fri Nov 9 10:13:58 2007 : Debug: Processing the authenticate section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authenticate for request 1 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 1 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: Request found, released from the list Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP/ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: processing type ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_ttls: Authenticate Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: processing TLS Fri Nov 9 10:13:58 2007 : Debug: eaptls_verify returned 7 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: Done initial handshake Fri Nov 9 10:13:58 2007 : Debug: (other): before/accept initialization Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: before/accept initialization Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0052], ClientHello Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 read client hello A Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 write server hello A Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0e3f], Certificate Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 write certificate A Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 028d], ServerKeyExchange Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 write key exchange A Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 write server done A Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 flush data Fri Nov 9 10:13:58 2007 : Error: TLS_accept:error in SSLv3 read client certificate A Fri Nov 9 10:13:58 2007 : Error: rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0) Fri Nov 9 10:13:58 2007 : Debug: In SSL Handshake Phase Fri Nov 9 10:13:58 2007 : Debug: In SSL Accept mode Fri Nov 9 10:13:58 2007 : Debug: eaptls_process returned 13 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 1 Fri Nov 9 10:13:58 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 1 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 1 Sending Access-Challenge of id 28 to 192.168.2.136 port 1067 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" EAP-Message = 0x011d040a15c00000112e160301004a020000460301473424d614cdc5f63f7c490da1816099aea7d098d3e49d74e5b2220e5bd92b0820d9c32bcd1babc24318e7bcf9940af5ee2a349c684fc84e4ffaf4c6a565f95af00039011603010e3f0b000e3b000e380007213082071d30820505a003020102020101300d06092a864886f70d010105050030818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f5241443119301706035504031410726163696e655f7261646975735f63613120301e06092a864886 EAP-Message = 0xf70d0109011611726f6f74406975742d6e696d65732e6672301e170d3037313031373134313634375a170d3137313031333134313634375a30818e310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f524144311c301a060355040313137261646975732e6975742d6e696d65732e66723120301e06092a864886f70d0109011611726f6f74406975742d6e696d65732e667230820222300d06092a864886f70d01010105000382020f003082020a0282020100b41f603426567257b79af7a1c55383b9f95630 EAP-Message = 0xa56da69afde35132613928b2769e8a5aed6971a578e507a00f486bbc665725c549845c8d122cc5d555d7631e884b40aeee88b300066297f4419097c0e47d911a6af99beadeb5522b82927c960628ebdf76d8e11005ec71d155130f3846890118e9d6b3959f5251da0e4dd6ef485691e3ac7367a3c7216600cea8c25562497f07ac5b2c4b88f6e28a3199a84c0caeaa2978116e9107ea413138dba61344d3fb3217565ca782366ab67d28de7ab7044cb96e1b4fdaad497ef12348cb4f173e93faf163378e4d9dbb3d28555734ee1049570e1a0026cf838b1775adfa4c8fd31579e5a5d78adfe22c78d02c8a281b593e879b2732ea256b154d5493236414 EAP-Message = 0xb9262c4c15e515fb040841e1fdb427a4d76a090242844af7b02d3059acda44bfb3235e479dc6b71ba61ce3da7338ce0b87bf501c4c49d49d3bf982d6f0ca490c7c0d84372bdc586d45315c2154fce654364e3eebc3dafd126b3257d77f96fd78f429b892293d09478866d41debd275f3a7b4411d49d6eb025ccff1d5f16cd74d42d8c6a7d33fcba89c389da11d415a5d9cd9bb0618cad78136c1350542ca6a7510682da4ff26788faad867e03535f05d12f4e1c14a0218cec63efa7ab20aead38731d3c7b87080fe3a4da8b74977e92ceb747c7887a4a1dfe30ec5abb7ad8d451866ddf9d1a965759ac903a40c74ee2f0203010001a382018530820181 EAP-Message = 0x30090603551d1304023000301106096086480186f842 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1c3235431a74fd4d4ba2ba6a54cf2408 Fri Nov 9 10:13:58 2007 : Debug: Finished request 1 Fri Nov 9 10:13:58 2007 : Debug: Going to the next request Fri Nov 9 10:13:58 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.136:1067, id=29, length=192 Message-Authenticator = 0xb32eb6623b0a8600f202c2ab5ec84bef Service-Type = Framed-User User-Name = "test88" Framed-MTU = 1488 State = 0x1c3235431a74fd4d4ba2ba6a54cf2408 Called-Station-Id = "00-18-6E-9A-49-40:eap" Calling-Station-Id = "00-16-6F-42-28-0F" NAS-Identifier = "3comeap" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x021d00061500 NAS-IP-Address = 192.168.2.136 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Fri Nov 9 10:13:58 2007 : Debug: Processing the authorize section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authorize for request 2 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 2 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP packet type response id 29 length 6 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 2 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 2 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 2 Fri Nov 9 10:13:58 2007 : Debug: users: Matched entry test88 at line 89 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 2 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "files" returns ok for request 2 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authorize (returns updated) for request 2 Fri Nov 9 10:13:58 2007 : Debug: rad_check_password: Found Auth-Type EAP Fri Nov 9 10:13:58 2007 : Debug: auth: type "EAP" Fri Nov 9 10:13:58 2007 : Debug: Processing the authenticate section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authenticate for request 2 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 2 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: Request found, released from the list Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP/ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: processing type ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_ttls: Authenticate Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: processing TLS Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: ack handshake fragment handler Fri Nov 9 10:13:58 2007 : Debug: eaptls_verify returned 1 Fri Nov 9 10:13:58 2007 : Debug: eaptls_process returned 13 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 2 Fri Nov 9 10:13:58 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 2 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 2 Sending Access-Challenge of id 29 to 192.168.2.136 port 1067 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" EAP-Message = 0x011e040a15c00000112e0101040403020640302b06096086480186f842010d041e161c54696e7943412047656e657261746564204365727469666963617465301d0603551d0e041604145e71168aa9388f5e560d055c69529a293bbfd4763081c00603551d230481b83081b5801450573acf65cdfb3d75565075c6bb595dcccc9fd1a18191a4818e30818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f5241443119301706035504031410726163696e655f7261646975735f63613120301e06092a8648 EAP-Message = 0x86f70d0109011611726f6f74406975742d6e696d65732e6672820900fdc00ec8e0a7815a301c0603551d12041530138111726f6f74406975742d6e696d65732e6672301c0603551d11041530138111726f6f74406975742d6e696d65732e667230160603551d250101ff040c300a06082b06010505070301300d06092a864886f70d01010505000382020100bfa653fd04981a61c719ea82621eb27a00668af0d8e3381acde6fef7e9b651621fce42f7fe72070bbe377390aeee3b66f4ee19615a5c42c4f152958647ee2a161d4cc6715d876f950b059877b0942c2d50c01d48aa5ec02545daa766db4edbb7ae942754b21486bb1205c9387d7a91a20d EAP-Message = 0x4c52d33934eb750bf306517ffcb24d3d1826b1eb9dca65610b4a90957a96e92cf9cbf4a5267c4c3b3f3438e82c169a81e73cae0bfb2d278ae08db316e26ff819affc4a256ec20cb4247b4a7330908959da4e54a3c87792e721cbfa07df8d98f7b609b51952c5fcc3efa4eb35bc985ca830ccf719ad9b40b47d10e9fc56095af4b0c64c1f219e00a05c725ab82ffa06f22c17923068fbc0801b1c50d3c1854b4eb06ef2afcef4d759913f5eddf33e37100c324dcb29bd53440a74fd689fe44c0e046bb667a634b59636df22a747b9de1016287f1bcbf55077be4b167539bda8da3d3f118387f56fc05442d67076b13a17d4eebdc1c93ea69169f5237c01 EAP-Message = 0xedb917dbd28e4ea951779e18260b4872afa105c8ccc445ca864c0aa24edf754544e2e79b2681010ea7a5e72d5d0ba0e9e9655f6ae8a75718c91d8773ed4d40c7697a34730b2fa5d41043a70642e4f9317fe57cae2643e2734cc39150b1e798c258e86e5da2bb4b71c01e457f855ab790ca889f2ced7e8af871a3ef5c3362cbaf5706336399040f2289a2a3bce30a33709a060007113082070d308204f5a003020102020900fdc00ec8e0a7815a300d06092a864886f70d010105050030818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110 EAP-Message = 0x300e060355040b14074955545f524144311930170603 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x9d5cfb6c9403a5db8329a3d3add3043d Fri Nov 9 10:13:58 2007 : Debug: Finished request 2 Fri Nov 9 10:13:58 2007 : Debug: Going to the next request Fri Nov 9 10:13:58 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.136:1067, id=30, length=192 Message-Authenticator = 0x4c64f3772ffc237388e512a07398dea9 Service-Type = Framed-User User-Name = "test88" Framed-MTU = 1488 State = 0x9d5cfb6c9403a5db8329a3d3add3043d Called-Station-Id = "00-18-6E-9A-49-40:eap" Calling-Station-Id = "00-16-6F-42-28-0F" NAS-Identifier = "3comeap" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x021e00061500 NAS-IP-Address = 192.168.2.136 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Fri Nov 9 10:13:58 2007 : Debug: Processing the authorize section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authorize for request 3 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 3 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP packet type response id 30 length 6 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 3 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 3 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 3 Fri Nov 9 10:13:58 2007 : Debug: users: Matched entry test88 at line 89 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 3 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "files" returns ok for request 3 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authorize (returns updated) for request 3 Fri Nov 9 10:13:58 2007 : Debug: rad_check_password: Found Auth-Type EAP Fri Nov 9 10:13:58 2007 : Debug: auth: type "EAP" Fri Nov 9 10:13:58 2007 : Debug: Processing the authenticate section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authenticate for request 3 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 3 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: Request found, released from the list Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP/ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: processing type ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_ttls: Authenticate Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: processing TLS Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: ack handshake fragment handler Fri Nov 9 10:13:58 2007 : Debug: eaptls_verify returned 1 Fri Nov 9 10:13:58 2007 : Debug: eaptls_process returned 13 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 3 Fri Nov 9 10:13:58 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 3 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 3 Sending Access-Challenge of id 30 to 192.168.2.136 port 1067 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" EAP-Message = 0x011f040a15c00000112e5504031410726163696e655f7261646975735f63613120301e06092a864886f70d0109011611726f6f74406975742d6e696d65732e6672301e170d3037313031373133343330355a170d3137313031343133343330355a30818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f5241443119301706035504031410726163696e655f7261646975735f63613120301e06092a864886f70d0109011611726f6f74406975742d6e696d65732e667230820222300d06092a864886f70d EAP-Message = 0x01010105000382020f003082020a0282020100c1768ae6fd481eaf9bec06a8a8f027a77ed587b81c0628e699dc331867010721e749fff40751b027a0fa389306b15a8ad06cc1659341ed04b24e7427d07804011fa33b6595cbed5d21b541bea2f07c6a1e76a29e00dab943efe93177391553d3fdaaf8d9644b86cc0ed17c60abb4333d785f696e327642b27a6dd7bd3b7979ee57bffeb8bd6f4d47410b28b6c98f9acc880bbdc56f165896b79bd5beb3c089ad811f85ad1b63a46164d535c4dd03392a85be6c7d65f4eda7932ecd5b916fbb639464213d5482803dc5f34943cdf0246d5991c470d2eae7c5dffe05c8e19b5e4e23a723cb0c6f0959af1c EAP-Message = 0x6e2aa2d356f786d78acec2498f7518dc1a15bdb202312e6bf3a39daaf70971359aa392e73452299cf20b1576a017efb62122dffb2ab347ee682aa3615b9b8f1601e46b33ab2889d40087ac0d9fc92c54283d9d48b405bdf2be5e6e338e2acc175b0ac63a4345a6f346ad0dff5eee00b548936aca7cead608b65539d8fde6cf3a11c739432741243bbafba4bd3fd4e83cef7a1468d87d94775a7eacda2856783676121238b317c9aaf25949d5897a8fc262e18c5f7dce8858396243920f521f65b485b9cd5e4b936bd014d34ee1cfc96c0a2a67a0e7dc2c8d2fdadc187c2f4728ff47ff123324c881374f7f54526476d6e91e646ef0f7df9f1b66efa63e EAP-Message = 0xa5cc0c37243d2acae9a3ed89fc68432257b83d080da587c5030203010001a38201703082016c301d0603551d0e0416041450573acf65cdfb3d75565075c6bb595dcccc9fd13081c00603551d230481b83081b5801450573acf65cdfb3d75565075c6bb595dcccc9fd1a18191a4818e30818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f5241443119301706035504031410726163696e655f7261646975735f63613120301e06092a864886f70d0109011611726f6f74406975742d6e696d65732e6672 EAP-Message = 0x820900fdc00ec8e0a7815a300f0603551d130101ff04 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x46882bc4783ecf928f9e9249f78b3bdd Fri Nov 9 10:13:58 2007 : Debug: Finished request 3 Fri Nov 9 10:13:58 2007 : Debug: Going to the next request Fri Nov 9 10:13:58 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.136:1067, id=31, length=192 Message-Authenticator = 0x77224a6af99075e4218c335270197e98 Service-Type = Framed-User User-Name = "test88" Framed-MTU = 1488 State = 0x46882bc4783ecf928f9e9249f78b3bdd Called-Station-Id = "00-18-6E-9A-49-40:eap" Calling-Station-Id = "00-16-6F-42-28-0F" NAS-Identifier = "3comeap" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x021f00061500 NAS-IP-Address = 192.168.2.136 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Fri Nov 9 10:13:58 2007 : Debug: Processing the authorize section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authorize for request 4 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 4 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP packet type response id 31 length 6 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 4 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 4 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 4 Fri Nov 9 10:13:58 2007 : Debug: users: Matched entry test88 at line 89 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 4 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "files" returns ok for request 4 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authorize (returns updated) for request 4 Fri Nov 9 10:13:58 2007 : Debug: rad_check_password: Found Auth-Type EAP Fri Nov 9 10:13:58 2007 : Debug: auth: type "EAP" Fri Nov 9 10:13:58 2007 : Debug: Processing the authenticate section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authenticate for request 4 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 4 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: Request found, released from the list Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP/ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: processing type ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_ttls: Authenticate Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: processing TLS Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: ack handshake fragment handler Fri Nov 9 10:13:58 2007 : Debug: eaptls_verify returned 1 Fri Nov 9 10:13:58 2007 : Debug: eaptls_process returned 13 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 4 Fri Nov 9 10:13:58 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 4 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 4 Sending Access-Challenge of id 31 to 192.168.2.136 port 1067 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" EAP-Message = 0x0120040a15c00000112e0530030101ff301106096086480186f842010104040302010630090603551d1204023000302b06096086480186f842010d041e161c54696e7943412047656e657261746564204365727469666963617465301c0603551d11041530138111726f6f74406975742d6e696d65732e6672300e0603551d0f0101ff040403020106300d06092a864886f70d01010505000382020100a5ddc9c739f4bf4ab6816f961849875fbf26eafd3d78cfd8ff8a06a00cbf2d4b92b3be41e052c071f640c310cbbafc42a5272175cd1d57b9f29d7755c579caf68f18458043f16b3ee3205e158d6dbfe0f0c9a9b91e373aec65da6a7685a80167 EAP-Message = 0xd82adf320568ed7f13f1c1a34077aaa26d2deb008ba7bdf5d7957f1e65edcad2999477968c4f4e2b19958b3b75a22ef87d21f22b82e0d552569d30ef005df0cf2ce51b1b5b9c0eb48154e0f018aefdca1ea1bacdf057cea2a665e0368619c6b9d2bbc594725154b5ad74edc538bf2e56c7166f589d405eca502618556d709662248e2a0aba8432f9d8c8608f9f29b8115a3c9ac9ae08e9411d27be1240e555dfdd2955e02094a2103aa2d4fa39fde98c81a2d384a7ee3bb9dbf5de186f1a9908ba17d8e73b1ea4fece4fd79bc45d426f18b7be65bbc0df7f6df3ab62f1f92ee720d97fcc4bba9faade8232939e1c9057723a6247a8b7e6f03aaf63a616 EAP-Message = 0x17aab7b3c9d2f6a351f981f93941d027558b6a29df8685285dcc0ba6ca17e28d6bb404c30812210c7d6be30558d6b71117c71b1e5d5a80cc8b9b133255a0f92636f404bbba2f65301796e8360955dbe6958d763b7ff33faa1495e5b9ebef8ed10ca39c904f435bbfca79a772237cead4bac8881646996100477d03091fc5f4cce5db151dc02cdb8fb0d4a0d50c344bfe57871889f13cdab4b25981fc0c251ae672207e160301028d0c0002890040e54527309c69a6f9b14f9a455b74e4427a66dc3886a1ef826a7b7fbb07bd8b71470270e0758bb20446c948c11f0c49339127ff5e06397ee77242c0b6087a51ef000105004038a4729f66fc680faff0 EAP-Message = 0xa67f4976b6c570ac9b4bf26d7329ad0146e1ff5c3504d49dda799a542cafac56169a986fde46e7a3ffc6a13bfcb488a224667cd6cd3602000b41100ff0622cc9c151c424d440d2d278f0458460f20449003f96f4a08e867139ddad96486227961650ef185141ee5e8476e961f363864c9f236efef0bb48d0002a26a1a99b3be10dce08d964fb66f65b3c65e0ccfe11329d08fd0ce9b3ad61f9deb161ac5ca91fad58bd1c42d34b62f67d20708d41e2b4c823c0e4a2172694401051b83a6d2a17b2a214f12430863673e9c58919531bc0d3317fef5445702c6fd5ab7065342bc01b6a0c25969a8b3ac7f43d4934ef90733ec6bc1718043e0d1c244e74e0 EAP-Message = 0xa5e083696ef825244f59dd34a4b79eb36d2fde633883 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x59529d4d47264ff7047cff71020f5ad5 Fri Nov 9 10:13:58 2007 : Debug: Finished request 4 Fri Nov 9 10:13:58 2007 : Debug: Going to the next request Fri Nov 9 10:13:58 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.136:1067, id=32, length=192 Message-Authenticator = 0x81487325bd7145bec596503c0cdfa330 Service-Type = Framed-User User-Name = "test88" Framed-MTU = 1488 State = 0x59529d4d47264ff7047cff71020f5ad5 Called-Station-Id = "00-18-6E-9A-49-40:eap" Calling-Station-Id = "00-16-6F-42-28-0F" NAS-Identifier = "3comeap" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x022000061500 NAS-IP-Address = 192.168.2.136 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Fri Nov 9 10:13:58 2007 : Debug: Processing the authorize section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authorize for request 5 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 5 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP packet type response id 32 length 6 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 5 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 5 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 5 Fri Nov 9 10:13:58 2007 : Debug: users: Matched entry test88 at line 89 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 5 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "files" returns ok for request 5 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authorize (returns updated) for request 5 Fri Nov 9 10:13:58 2007 : Debug: rad_check_password: Found Auth-Type EAP Fri Nov 9 10:13:58 2007 : Debug: auth: type "EAP" Fri Nov 9 10:13:58 2007 : Debug: Processing the authenticate section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authenticate for request 5 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 5 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: Request found, released from the list Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP/ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: processing type ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_ttls: Authenticate Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: processing TLS Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: ack handshake fragment handler Fri Nov 9 10:13:58 2007 : Debug: eaptls_verify returned 1 Fri Nov 9 10:13:58 2007 : Debug: eaptls_process returned 13 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 5 Fri Nov 9 10:13:58 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 5 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 5 Sending Access-Challenge of id 32 to 192.168.2.136 port 1067 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" EAP-Message = 0x0121013815800000112efa61a7eb64c36763345961c050a4deca07a623145ff7ed7191dd11faf05680c040a1b984deff6a9aff5e32fddaf367b168addfaa9bc900f58d125a4b6f7db814c635af55c017cee93ea04bf1f937c40b353a802fb2ea1cf955b5f2058429b8d9f1d09249bb51ea827213c2e63a23eb7ddfbbb15e16bc2a53e55b48e05d6d0af80edbbeb0ac2d1095738d621c7c2447f1b6714fdaf4d47b550f8ed6da0a532a3f3b23bc7ff06cccd25b7841ef0000f00ac6b96407589ca87bff317c6575050a745e7c4189c5f651581659b2f430b1c962fa168f31300616833c348c9096a19c3f11855a2202b08d86166fbacb025ffabfc54e77 EAP-Message = 0x7a4bf8a5d15b1e5e6e45a60dd18b8b01ed6f8dc2c85b732b80b0c44bc91e9115288dba0456baac6ec5cd3bdd3069530a7fb216030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2a1973f2f0e864b9d2daf9614a03dcfb Fri Nov 9 10:13:58 2007 : Debug: Finished request 5 Fri Nov 9 10:13:58 2007 : Debug: Going to the next request Fri Nov 9 10:13:58 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.136:1067, id=33, length=326 Message-Authenticator = 0xb1bf1dd835788bdba02ca5c972c927d2 Service-Type = Framed-User User-Name = "test88" Framed-MTU = 1488 State = 0x2a1973f2f0e864b9d2daf9614a03dcfb Called-Station-Id = "00-18-6E-9A-49-40:eap" Calling-Station-Id = "00-16-6F-42-28-0F" NAS-Identifier = "3comeap" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x0221008c15001603010046100000420040a6844192dda9f96857f865018016aa092fb6bba52a05e2dea4121d9db1dfbb8174e5066d099c8017dd7b4541fa95baa9af034191f0e257c2557fbb32967da20514030100010116030100300a0e675a9c9f9bf4d193f71bed9f980f4f9ab0b2643ae52f7456f524200142d83e4e45e39421908c536e9d4464ed3208 NAS-IP-Address = 192.168.2.136 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Fri Nov 9 10:13:58 2007 : Debug: Processing the authorize section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authorize for request 6 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 6 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP packet type response id 33 length 140 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 6 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 6 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 6 Fri Nov 9 10:13:58 2007 : Debug: users: Matched entry test88 at line 89 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 6 Fri Nov 9 10:13:58 2007 : Debug: modcall[authorize]: module "files" returns ok for request 6 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authorize (returns updated) for request 6 Fri Nov 9 10:13:58 2007 : Debug: rad_check_password: Found Auth-Type EAP Fri Nov 9 10:13:58 2007 : Debug: auth: type "EAP" Fri Nov 9 10:13:58 2007 : Debug: Processing the authenticate section of radiusd.conf Fri Nov 9 10:13:58 2007 : Debug: modcall: entering group authenticate for request 6 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 6 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: Request found, released from the list Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: EAP/ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap: processing type ttls Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_ttls: Authenticate Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: processing TLS Fri Nov 9 10:13:58 2007 : Debug: eaptls_verify returned 7 Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: Done initial handshake Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 read client key exchange A Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001] Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 read finished A Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001] Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 write change cipher spec A Fri Nov 9 10:13:58 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 write finished A Fri Nov 9 10:13:58 2007 : Debug: TLS_accept: SSLv3 flush data Fri Nov 9 10:13:58 2007 : Debug: (other): SSL negotiation finished successfully Fri Nov 9 10:13:58 2007 : Error: rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0) Fri Nov 9 10:13:58 2007 : Debug: SSL Connection Established Fri Nov 9 10:13:58 2007 : Debug: eaptls_process returned 13 Fri Nov 9 10:13:58 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 6 Fri Nov 9 10:13:58 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 6 Fri Nov 9 10:13:58 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 6 Sending Access-Challenge of id 33 to 192.168.2.136 port 1067 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" EAP-Message = 0x0122004515800000003b1403010001011603010030748c180ed5aeb0c6cb5904d6ed1ecd99918e7483a9a9e7e813cc0b1cd40a5b8dbe30bca40912e85da1685ef09787b890 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbd0bc2de964e06859f41e9de677beb32 Fri Nov 9 10:13:58 2007 : Debug: Finished request 6 Fri Nov 9 10:13:58 2007 : Debug: Going to the next request Fri Nov 9 10:13:58 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.136:1067, id=34, length=298 Message-Authenticator = 0xd1c723457a5b6ee40d31f56a8ef63066 Service-Type = Framed-User User-Name = "test88" Framed-MTU = 1488 State = 0xbd0bc2de964e06859f41e9de677beb32 Called-Station-Id = "00-18-6E-9A-49-40:eap" Calling-Station-Id = "00-16-6F-42-28-0F" NAS-Identifier = "3comeap" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x022200701500170301002027428965475f2914dc59e2399ee15f4bd0c64242e54854ed7d30487b26f916541703010040247e769840abb023d2e402caf508eb2e79d7435cc9baad9249d3dd6cfb9e6f6f6a8291dcde57fabbdf84e72483a2ab1c7e8d3c84945d7c86243443c600330609 NAS-IP-Address = 192.168.2.136 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Fri Nov 9 10:13:59 2007 : Debug: Processing the authorize section of radiusd.conf Fri Nov 9 10:13:59 2007 : Debug: modcall: entering group authorize for request 7 Fri Nov 9 10:13:59 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 7 Fri Nov 9 10:13:59 2007 : Debug: rlm_eap: EAP packet type response id 34 length 112 Fri Nov 9 10:13:59 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Fri Nov 9 10:13:59 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 7 Fri Nov 9 10:13:59 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 7 Fri Nov 9 10:13:59 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 7 Fri Nov 9 10:13:59 2007 : Debug: users: Matched entry test88 at line 89 Fri Nov 9 10:13:59 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 7 Fri Nov 9 10:13:59 2007 : Debug: modcall[authorize]: module "files" returns ok for request 7 Fri Nov 9 10:13:59 2007 : Debug: modcall: leaving group authorize (returns updated) for request 7 Fri Nov 9 10:13:59 2007 : Debug: rad_check_password: Found Auth-Type EAP Fri Nov 9 10:13:59 2007 : Debug: auth: type "EAP" Fri Nov 9 10:13:59 2007 : Debug: Processing the authenticate section of radiusd.conf Fri Nov 9 10:13:59 2007 : Debug: modcall: entering group authenticate for request 7 Fri Nov 9 10:13:59 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 7 Fri Nov 9 10:13:59 2007 : Debug: rlm_eap: Request found, released from the list Fri Nov 9 10:13:59 2007 : Debug: rlm_eap: EAP/ttls Fri Nov 9 10:13:59 2007 : Debug: rlm_eap: processing type ttls Fri Nov 9 10:13:59 2007 : Debug: rlm_eap_ttls: Authenticate Fri Nov 9 10:13:59 2007 : Debug: rlm_eap_tls: processing TLS Fri Nov 9 10:13:59 2007 : Debug: eaptls_verify returned 7 Fri Nov 9 10:13:59 2007 : Debug: rlm_eap_tls: Done initial handshake Fri Nov 9 10:13:59 2007 : Debug: eaptls_process returned 7 Fri Nov 9 10:13:59 2007 : Debug: rlm_eap_ttls: Session established. Proceeding to decode tunneled attributes. TTLS tunnel data in 0000: 00 00 00 01 40 00 00 0e 74 65 73 74 38 38 00 00 TTLS tunnel data in 0010: 00 00 00 02 40 00 00 18 70 61 73 73 74 65 73 74 TTLS tunnel data in 0020: 38 38 00 00 00 00 00 00 TTLS: Got tunneled request User-Name = "test88" User-Password = "passtest88" FreeRADIUS-Proxied-To = 127.0.0.1 TTLS: Sending tunneled request User-Name = "test88" User-Password = "passtest88" FreeRADIUS-Proxied-To = 127.0.0.1 Service-Type = Framed-User Framed-MTU = 1488 Called-Station-Id = "00-18-6E-9A-49-40:eap" Calling-Station-Id = "00-16-6F-42-28-0F" NAS-Identifier = "3comeap" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" NAS-IP-Address = 192.168.2.136 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Fri Nov 9 10:13:59 2007 : Debug: Processing the authorize section of radiusd.conf Fri Nov 9 10:13:59 2007 : Debug: modcall: entering group authorize for request 7 Fri Nov 9 10:13:59 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 7 Fri Nov 9 10:13:59 2007 : Debug: rlm_eap: No EAP-Message, not doing EAP Fri Nov 9 10:13:59 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 7 Fri Nov 9 10:13:59 2007 : Debug: modcall[authorize]: module "eap" returns noop for request 7 Fri Nov 9 10:13:59 2007 : Debug: modsingle[authorize]: calling files (rlm_files) for request 7 Fri Nov 9 10:13:59 2007 : Debug: users: Matched entry test88 at line 89 Fri Nov 9 10:13:59 2007 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 7 Fri Nov 9 10:13:59 2007 : Debug: modcall[authorize]: module "files" returns ok for request 7 Fri Nov 9 10:13:59 2007 : Debug: modcall: leaving group authorize (returns ok) for request 7 Fri Nov 9 10:13:59 2007 : Debug: auth: type Local Fri Nov 9 10:13:59 2007 : Debug: auth: user supplied User-Password matches local User-Password TTLS: Got tunneled reply RADIUS code 2 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" Fri Nov 9 10:13:59 2007 : Debug: TTLS: Got tunneled Access-Accept Fri Nov 9 10:13:59 2007 : Debug: rlm_eap: Freeing handler Fri Nov 9 10:13:59 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 7 Fri Nov 9 10:13:59 2007 : Debug: modcall[authenticate]: module "eap" returns ok for request 7 Fri Nov 9 10:13:59 2007 : Debug: modcall: leaving group authenticate (returns ok) for request 7 Sending Access-Accept of id 34 to 192.168.2.136 port 1067 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "88" MS-MPPE-Recv-Key = 0x9532a94e83def6d946f8fad11fdd6ffba23fa797a90c77c6369f326b9580839e MS-MPPE-Send-Key = 0xa1d35c5041047126400a7226508b58e7fc889813ec39139b4ff3d58eec13f86d EAP-Message = 0x03220004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "test88" Fri Nov 9 10:13:59 2007 : Debug: Finished request 7 Fri Nov 9 10:13:59 2007 : Debug: Going to the next request Fri Nov 9 10:13:59 2007 : Debug: --- Walking the entire request list --- Fri Nov 9 10:13:59 2007 : Debug: Waking up in 5 seconds... Fri Nov 9 10:14:04 2007 : Debug: --- Walking the entire request list --- Fri Nov 9 10:14:04 2007 : Debug: Cleaning up request 0 ID 27 with timestamp 473424d6 Fri Nov 9 10:14:04 2007 : Debug: Cleaning up request 1 ID 28 with timestamp 473424d6 Fri Nov 9 10:14:04 2007 : Debug: Cleaning up request 2 ID 29 with timestamp 473424d6 Fri Nov 9 10:14:04 2007 : Debug: Cleaning up request 3 ID 30 with timestamp 473424d6 Fri Nov 9 10:14:04 2007 : Debug: Cleaning up request 4 ID 31 with timestamp 473424d6 Fri Nov 9 10:14:04 2007 : Debug: Cleaning up request 5 ID 32 with timestamp 473424d6 Fri Nov 9 10:14:04 2007 : Debug: Cleaning up request 6 ID 33 with timestamp 473424d6 Fri Nov 9 10:14:04 2007 : Debug: Waking up in 1 seconds... Fri Nov 9 10:14:05 2007 : Debug: --- Walking the entire request list --- Fri Nov 9 10:14:05 2007 : Debug: Cleaning up request 7 ID 34 with timestamp 473424d7 Fri Nov 9 10:14:05 2007 : Debug: Nothing to do. Sleeping until we see a request. DEBUG WPA SUPLLICANT wpa_supplicant -d -i "eth2" -D "wext" -c /etc/wpa_supplicant/wpa_supplicant.conf > debug.txt Initializing interface 'eth2' conf '/etc/wpa_supplicant/wpa_supplicant.conf' driver 'wext' ctrl_interface 'N/A' bridge 'N/A' Configuration file '/etc/wpa_supplicant/wpa_supplicant.conf' -> '/etc/wpa_supplicant/wpa_supplicant.conf' Reading configuration file '/etc/wpa_supplicant/wpa_supplicant.conf' ctrl_interface='/var/run/wpa_supplicant' Priority group 0 id=0 ssid='sjp' id=1 ssid='eap' Initializing interface (2) 'eth2' EAPOL: SUPP_PAE entering state DISCONNECTED EAPOL: KEY_RX entering state NO_KEY_RECEIVE EAPOL: SUPP_BE entering state INITIALIZE EAP: EAP entering state DISABLED EAPOL: External notification - portEnabled=0 EAPOL: External notification - portValid=0 SIOCGIWRANGE: WE(compiled)=20 WE(source)=18 enc_capa=0xf capabilities: key_mgmt 0xf enc 0xf WEXT: Operstate: linkmode=1, operstate=5 Own MAC address: 00:16:6f:42:28:0f wpa_driver_wext_set_wpa wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0 wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0 wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0 wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0 wpa_driver_wext_set_countermeasures wpa_driver_wext_set_drop_unencrypted Setting scan request: 0 sec 100000 usec Added interface eth2 RTM_NEWLINK: operstate=0 ifi_flags=0x1002 () Wireless event: cmd=0x8b06 len=8 RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP]) RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP]) RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP]) Wireless event: cmd=0x8b19 len=8 Received 840 bytes of scan results (3 BSSes) Scan results: 3 Selecting BSS from priority group 0 0: 00:18:6e:9a:49:40 ssid='eap' wpa_ie_len=24 rsn_ie_len=22 caps=0x11 skip - SSID mismatch selected based on WPA IE Trying to associate with 00:18:6e:9a:49:40 (SSID='eap' freq=0 MHz) Cancelling scan request WPA: clearing own WPA/RSN IE Automatic auth_alg selection: 0x1 WPA: using IEEE 802.11i/D3.0 WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 1 proto 1 WPA: set AP WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 02 01 00 00 0f ac 01 01 00 WPA: using GTK TKIP WPA: using PTK TKIP WPA: using KEY_MGMT 802.1X WPA: Set own WPA IE default - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 No keys have been configured - skip key clearing wpa_driver_wext_set_drop_unencrypted State: DISCONNECTED -> ASSOCIATING wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT) WEXT: Operstate: linkmode=-1, operstate=5 wpa_driver_wext_associate Setting authentication timeout: 10 sec 0 usec EAPOL: External notification - portControl=Auto RSN: added PMKSA cache candidate 00:18:6e:9a:49:40 prio 1000 RSN: processing PMKSA candidate list RSN: not in suitable state for new pre-authentication RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP]) Wireless event: cmd=0x8b06 len=8 RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP]) Wireless event: cmd=0x8b1a len=12 RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) Wireless event: cmd=0x8b15 len=20 Wireless event: new AP: 00:18:6e:9a:49:40 State: ASSOCIATING -> ASSOCIATED wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT) WEXT: Operstate: linkmode=-1, operstate=5 Associated to a new BSS: BSSID=00:18:6e:9a:49:40 No keys have been configured - skip key clearing Associated with 00:18:6e:9a:49:40 WPA: Association event - clear replay counter EAPOL: External notification - portEnabled=0 EAPOL: External notification - portValid=0 EAPOL: External notification - portEnabled=1 EAPOL: SUPP_PAE entering state CONNECTING EAPOL: SUPP_BE entering state IDLE EAP: EAP entering state INITIALIZE EAP: EAP entering state IDLE Setting authentication timeout: 10 sec 0 usec Cancelling scan request RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP]) RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added EAPOL: startWhen --> 0 EAPOL: SUPP_PAE entering state CONNECTING EAPOL: txStart RX EAPOL from 00:18:6e:9a:49:40 Setting authentication timeout: 70 sec 0 usec EAPOL: Received EAP-Packet frame EAPOL: SUPP_PAE entering state RESTART EAP: EAP entering state INITIALIZE EAP: EAP entering state IDLE EAPOL: SUPP_PAE entering state AUTHENTICATING EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=27 method=1 vendor=0 vendorMethod=0 EAP: EAP entering state IDENTITY CTRL-EVENT-EAP-STARTED EAP authentication started EAP: EAP-Request Identity data - hexdump_ascii(len=0): EAP: using anonymous identity - hexdump_ascii(len=6): 74 65 73 74 38 38 test88 EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=28 method=21 vendor=0 vendorMethod=0 EAP: EAP entering state GET_METHOD EAP: Initialize selected EAP method: vendor 0 method 21 (TTLS) EAP-TTLS: Phase2 type: PAP CTRL-EVENT-EAP-METHOD EAP vendor 0 method 21 (TTLS) selected EAP: EAP entering state METHOD SSL: Received packet(len=6) - Flags 0x20 EAP-TTLS: Start (server ver=0, own ver=0) EAP-TTLS: Using TTLS version 0 TLS: Trusted root certificate(s) loaded EAP-TTLS: Start SSL: (where=0x10 ret=0x1) SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:before/connect initialization SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 write client hello A SSL: (where=0x1002 ret=0xffffffff) SSL: SSL_connect:error in SSLv3 read server hello A SSL: SSL_connect - want more data SSL: 87 bytes pending from ssl_out SSL: 87 bytes left to be sent out (of total 87 bytes) EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=29 method=21 vendor=0 vendorMethod=0 EAP: EAP entering state METHOD SSL: Received packet(len=1034) - Flags 0xc0 SSL: TLS Message Length: 4398 SSL: Need 3374 bytes more input data SSL: Building ACK EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=30 method=21 vendor=0 vendorMethod=0 EAP: EAP entering state METHOD SSL: Received packet(len=1034) - Flags 0xc0 SSL: TLS Message Length: 4398 SSL: Need 2350 bytes more input data SSL: Building ACK EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=31 method=21 vendor=0 vendorMethod=0 EAP: EAP entering state METHOD SSL: Received packet(len=1034) - Flags 0xc0 SSL: TLS Message Length: 4398 SSL: Need 1326 bytes more input data SSL: Building ACK EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=32 method=21 vendor=0 vendorMethod=0 EAP: EAP entering state METHOD SSL: Received packet(len=1034) - Flags 0xc0 SSL: TLS Message Length: 4398 SSL: Need 302 bytes more input data SSL: Building ACK EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=33 method=21 vendor=0 vendorMethod=0 EAP: EAP entering state METHOD SSL: Received packet(len=312) - Flags 0x80 SSL: TLS Message Length: 4398 SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 read server hello A TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) depth=1 buf='/C=FR/ST=France/L=Nimes/O=IUT/OU=IUT_RAD/CN=racine_radius_ca/emailAddress=root(a)iut-nimes.fr' TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) depth=0 buf='/C=FR/ST=France/L=Nimes/O=IUT/OU=IUT_RAD/CN=radius.iut-nimes.fr/emailAddress=root(a)iut-nimes.fr' SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 read server certificate A SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 read server key exchange A SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 read server done A SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 write client key exchange A SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 write change cipher spec A SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 write finished A SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 flush data SSL: (where=0x1002 ret=0xffffffff) SSL: SSL_connect:error in SSLv3 read finished A SSL: SSL_connect - want more data SSL: 134 bytes pending from ssl_out SSL: 134 bytes left to be sent out (of total 134 bytes) EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=34 method=21 vendor=0 vendorMethod=0 EAP: EAP entering state METHOD SSL: Received packet(len=69) - Flags 0x80 SSL: TLS Message Length: 59 SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 read finished A SSL: (where=0x20 ret=0x1) SSL: (where=0x1002 ret=0x1) SSL: 0 bytes pending from ssl_out OpenSSL: tls_connection_handshake - Failed to read possible Application Data error:00000000:lib(0):func(0):reason(0) SSL: No data to be sent out EAP-TTLS: TLS done, proceed to Phase 2 EAP-TTLS: Derived key - hexdump(len=64): [REMOVED] EAP-TTLS: received 0 bytes encrypted data for Phase 2 EAP-TTLS: empty data in beginning of Phase 2 - use fake EAP-Request Identity EAP-TTLS: Phase 2 PAP Request EAP-TTLS: Encrypting Phase 2 data - hexdump(len=40): [REMOVED] EAP-TTLS: Authentication completed successfully EAP: method process -> ignore=FALSE methodState=DONE decision=COND_SUCC EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Success EAP: EAP entering state SUCCESS CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully EAPOL: SUPP_BE entering state RECEIVE EAPOL: SUPP_BE entering state SUCCESS EAPOL: SUPP_BE entering state IDLE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines IEEE 802.1X RX: version=1 type=3 length=95 EAPOL-Key type=254 key_info 0x89 (ver=1 keyidx=0 rsvd=0 Pairwise Ack) key_length=32 key_data_length=0 replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 0e key_nonce - hexdump(len=32): ba 6d 7a 29 4b fb ae e3 0c 72 31 b1 7c 86 8f bc d8 ec fb cc 17 7e fd 63 c6 d4 30 db 95 82 bc e3 key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00 key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00 key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 State: ASSOCIATED -> 4WAY_HANDSHAKE WPA: RX message 1 of 4-Way Handshake from 00:18:6e:9a:49:40 (ver=1) WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED] WPA: Renewed SNonce - hexdump(len=32): b4 b6 69 9a 88 23 e3 6a e5 b9 aa 6a 1a 96 bd 52 a3 11 39 5b ff 8a f6 74 9e 1a 96 ab 62 f2 3b f7 WPA: PMK - hexdump(len=32): [REMOVED] WPA: PTK - hexdump(len=64): [REMOVED] WPA: WPA IE for msg 2/4 - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 WPA: Sending EAPOL-Key 2/4 RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines IEEE 802.1X RX: version=1 type=3 length=119 EAPOL-Key type=254 key_info 0x1c9 (ver=1 keyidx=0 rsvd=0 Pairwise Install Ack MIC) key_length=32 key_data_length=24 replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 0f key_nonce - hexdump(len=32): ba 6d 7a 29 4b fb ae e3 0c 72 31 b1 7c 86 8f bc d8 ec fb cc 17 7e fd 63 c6 d4 30 db 95 82 bc e3 key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00 key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00 key_mic - hexdump(len=16): bf e3 38 d7 41 93 34 33 55 f7 ce 50 14 2e b1 fd State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE WPA: RX message 3 of 4-Way Handshake from 00:18:6e:9a:49:40 (ver=1) WPA: IE KeyData - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 WPA: Sending EAPOL-Key 4/4 WPA: Installing PTK to the driver. WPA: RSC - hexdump(len=6): 00 00 00 00 00 00 wpa_driver_wext_set_key: alg=2 key_idx=0 set_tx=1 seq_len=6 key_len=32 State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE RX EAPOL from 00:18:6e:9a:49:40 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines IEEE 802.1X RX: version=1 type=3 length=127 EAPOL-Key type=254 key_info 0x3b1 (ver=1 keyidx=3 rsvd=0 Group Ack MIC Secure) key_length=32 key_data_length=32 replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 10 key_nonce - hexdump(len=32): f7 a5 9a e3 ed 43 f9 e7 85 c8 66 d7 e3 fe 58 38 5d ca 2d 88 38 7d 89 22 67 b4 8a 06 6c fe cd b8 key_iv - hexdump(len=16): 3c f1 ff 2b 28 05 c6 a5 f0 6f 67 d8 e7 a7 fa 92 key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00 key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00 key_mic - hexdump(len=16): 82 79 18 3f fe 79 21 09 81 1e 1b 89 89 8d 9f d5 WPA: RX message 1 of Group Key or STAKey Handshake from 00:18:6e:9a:49:40 (ver=1) State: GROUP_HANDSHAKE -> GROUP_HANDSHAKE WPA: Group Key - hexdump(len=32): [REMOVED] WPA: Installing GTK to the driver (keyidx=3 tx=0). WPA: RSC - hexdump(len=6): 00 00 00 00 00 00 wpa_driver_wext_set_key: alg=2 key_idx=3 set_tx=0 seq_len=6 key_len=32 WPA: Sending EAPOL-Key 2/2 WPA: Key negotiation completed with 00:18:6e:9a:49:40 [PTK=TKIP GTK=TKIP] Cancelling authentication timeout State: GROUP_HANDSHAKE -> COMPLETED CTRL-EVENT-CONNECTED - Connection to 00:18:6e:9a:49:40 completed (auth) [id=1 id_str=] wpa_driver_wext_set_operstate: operstate 0->1 (UP) WEXT: Operstate: linkmode=-1, operstate=6 EAPOL: External notification - portValid=1 EAPOL: SUPP_PAE entering state AUTHENTICATED RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP]) RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added RSN: processing PMKSA candidate list RSN: not in suitable state for new pre-authentication EAPOL: startWhen --> 0 CTRL-EVENT-TERMINATING - signal 2 received Removing interface eth2 State: COMPLETED -> DISCONNECTED wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT) WEXT: Operstate: linkmode=-1, operstate=5 wpa_driver_wext_deauthenticate wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0 wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0 wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0 wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0 wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0 EAPOL: External notification - portEnabled=0 EAPOL: SUPP_PAE entering state DISCONNECTED EAPOL: SUPP_BE entering state INITIALIZE EAP: EAP entering state DISABLED EAPOL: External notification - portValid=0 wpa_driver_wext_set_wpa wpa_driver_wext_set_drop_unencrypted wpa_driver_wext_set_countermeasures No keys have been configured - skip key clearing WEXT: Operstate: linkmode=0, operstate=6 EAP: deinitialize previously used EAP method (21, TTLS) at EAP deinit ENGINE: engine deinit Cancelling scan request

3 2

acct_users config
by Lin Bin-ABL045 08 Nov '07

08 Nov '07

Hi there, can anybody share experience in how to config the acct_users file? Thanks.

2 1

Received conflicting packet
by Norbert Wegener 08 Nov '07

08 Nov '07

With my actual freeradius cvs I have some messages like this ones: | 2007-11-08 11:37:07 | radiusd[17266]: Received conflicting packet from client 119.25.50.234 port 33496 - ID: 37 due to unfinished request 140423. Giving up on old request. | | 2007-11-08 11:37:07 | radiusd[17266]: Received conflicting packet from client 119.25.50.234 port 33512 - ID: 205 due to unfinished request 140435. Giving up on old request. | | 2007-11-08 19:04:11 | radiusd[22818]: Received conflicting packet from client 119.25.50.234 port 36363 - ID: 181 due to unfinished request 50778. Giving up on old request. | | 2007-11-08 19:04:17 | radiusd[22818]: Received conflicting packet from client 119.25.50.234 port 36363 - ID: 181 due to unfinished request 50779. Giving up on old request. | | 2007-11-08 19:04:28 | radiusd[22818]: Received conflicting packet from client 119.25.50.234 port 36363 - ID: 64 due to unfinished request 50783. Giving up on old request. | What causes those messages? I suppose, it might be serious? Norbert Wegener

2 1

Restricting user by realm
by Lisa Casey 08 Nov '07

08 Nov '07

Hi, I have Freeradius 1.1.6 running on FreeBSD. I authenticate users from a users file, not from a database. I have three default realms setup in the realms file and at the top of the users file like so: DEFAULT Realm == jellico.net Service-Type = Framed-User, Framed-Protocol = PPP, Framed-IP-Address = 255.255.255.254, Framed-IP-Netmask = 255.255.255.255, Framed-Routing = None, Framed-Compression = None, Framed-MTU = 1500, Fall-Through = 1 DEFAULT Realm == jellico.com Service-Type = Framed-User, Framed-Protocol = PPP, Framed-IP-Address = 255.255.255.254, Framed-IP-Netmask = 255.255.255.255, Framed-Routing = None, Framed-Compression = None, Framed-MTU = 1500, Fall-Through = 1 Then a list of users follows. Here's one example: lisa Auth-Type = Local, Password == xxxxxxx Service-Type = Framed-User, Framed-Protocol = PPP, Framed-IP-Address = 255.255.255.254, Framed-IP-Netmask = 255.255.255.255, Framed-Routing = None, Framed-Compression = None, Framed-MTU = 1500, Slipstream-Auth = "true" The way things are setup now, any user can log in with any of the realms I have defined. For example, I (username lisa) could login as lisa(a)jellico.com and then turn around and login as lisa(a)jellico.net My boss would like me to restrict this so that (for example) lisa could log in as lisa(a)jellico.com but not lisa(a)jellico.net With my setup, can I do this easily (or at all)? If this is possible, please give me some idea of how to go about doing this. Thanks, Lisa Casey

5 5