November 2007 - Freeradius-Users - lists.freeradius.org

Mikrotik ignores Framed-IP-Address
by Marinko Tarlac 12 Nov '07

12 Nov '07

Hello I have freeradius and Mikrotik combination and here is the problem. Freeradius is configured to use mysql database. When I add Framed-IP-Address for certain user (in radreply table) For example 32 user Framed-IP-Address 10.51.8.152 := It works but only if I don't have IP pool created on Mikrotik. If I create IP pool than Framed-IP-Address is ignored. Framed-Pool is specified for every group and attributes for every group is added in radgroupreply table. Log without IP pool rad_recv: Access-Request packet from host 192.168.1.7:1026, id=229, length=149 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 870 NAS-Port-Type = Ethernet User-Name = "admin-test" Calling-Station-Id = "00:C0:CA:18:75:B3" Called-Station-Id = "radius" NAS-Port-Id = "ether1" CHAP-Challenge = 0x89a28dc77659b6311a88c16eb7500767 CHAP-Password = 0x01d385ce5c814c1d1db9cafadb4736c351 NAS-Identifier = "1.7 - h-0" NAS-IP-Address = 192.168.1.7 rlm_chap: Setting 'Auth-Type := CHAP' rlm_sql (sql): Reserving sql socket id: 4 rlm_sql (sql): Released sql socket id: 4 rlm_chap: login attempt by "admin-test" with CHAP password rlm_chap: Using clear text password "perica" for user admin-test authentication. rlm_chap: chap user admin-test authenticated succesfully Sending Access-Accept of id 229 to 192.168.1.7 port 1026 Framed-IP-Address := 192.168.8.152 Framed-MTU = 576 Service-Type = Framed-User Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP Ascend-Data-Rate := 0 Ascend-Xmit-Rate := 0 Framed-Pool := "radius" Log with created IP pool called "radius" rad_recv: Access-Request packet from host 192.168.1.7:1027, id=240, length=149 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 872 NAS-Port-Type = Ethernet User-Name = "admin-test" Calling-Station-Id = "00:C0:CA:18:75:B3" Called-Station-Id = "radius" NAS-Port-Id = "ether1" CHAP-Challenge = 0x5293ac8321ad51693a5e3109f8887511 CHAP-Password = 0x01b0a9f7bca1f632878bee51c13d667f5c NAS-Identifier = "1.7 - h-0" NAS-IP-Address = 192.168.1.7 rlm_chap: Setting 'Auth-Type := CHAP' rlm_sql (sql): Reserving sql socket id: 4 rlm_sql (sql): Released sql socket id: 4 rlm_chap: login attempt by "admin-test" with CHAP password rlm_chap: Using clear text password "perica" for user admin-test authentication. rlm_chap: chap user admin-test authenticated succesfully Sending Access-Accept of id 240 to 192.168.1.7 port 1027 Framed-IP-Address := 192.168.8.152 Framed-MTU = 576 Service-Type = Framed-User Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP Ascend-Data-Rate := 0 Ascend-Xmit-Rate := 0 Framed-Pool := "radius" rad_recv: Accounting-Request packet from host 192.168.1.7:1027, id=241, length=146 Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 872 NAS-Port-Type = Ethernet User-Name = "admin-test" Calling-Station-Id = "00:C0:CA:18:75:B3" Called-Station-Id = "radius" NAS-Port-Id = "ether1" Acct-Session-Id = "81d00316" Framed-IP-Address = 192.168.8.159 Acct-Authentic = RADIUS Acct-Status-Type = Start NAS-Identifier = "1.7 - h-0" NAS-IP-Address = 192.168.1.7 Acct-Delay-Time = 0 rlm_sql (sql): Reserving sql socket id: 3 rlm_sql (sql): Released sql socket id: 3 Sending Accounting-Response of id 241 to 192.168.1.7 port 1027 Any ideas?

2 1

radius server and MAC authentication for wireless
by Shawn Adams 11 Nov '07

11 Nov '07

I've noted that some wireless APs using MAC/MAC authentication send the MAC in the form: 11-22-33-44-55-66 or 11:22:33:44:55:66 or 112233445566 The last seems most prevelent. Is there a method to configure $RADIUS/user.conf or $RADIUS/radiusd.conf (or other file) to allow the radius to authenticate *both* with one user entry ? I guess I'm thinking about a user.conf entry which allows PC_X to attach to Access_point_A and authenticate when the userid/password is sent 112233445566 *and* allow the same PC, when roaming to Access_point_B to authenticate with 11-22-33-44-55-66 using only one users.conf entry. Any help appreciated. Thanks

4 13

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