hi, i use freeradius with eap -peap and MySQL...but the freeradius don't send an access-accept at the end of authentication ...the server send an access-challenge,i don't know what's the problem... i'use a hp 2650 switch client,and a win xp supplicant, this is the the result of the debug mode.. Wed May 9 17:51:58 2007 : Info: Starting - reading configuration files ... Wed May 9 17:51:58 2007 : Debug: reread_config: reading radiusd.conf Wed May 9 17:51:58 2007 : Debug: Config: including file: /etc/freeradius/proxy.conf Wed May 9 17:51:58 2007 : Debug: Config: including file: /etc/freeradius/clients.conf Wed May 9 17:51:58 2007 : Debug: Config: including file: /etc/freeradius/snmp.conf Wed May 9 17:51:58 2007 : Debug: Config: including file: /etc/freeradius/eap.conf Wed May 9 17:51:58 2007 : Debug: Config: including file: /etc/freeradius/sql.conf Wed May 9 17:51:58 2007 : Debug: main: prefix = "/usr" Wed May 9 17:51:58 2007 : Debug: main: localstatedir = "/var" Wed May 9 17:51:58 2007 : Debug: main: logdir = "/var/log/freeradius" Wed May 9 17:51:58 2007 : Debug: main: libdir = "/usr/lib/freeradius" Wed May 9 17:51:58 2007 : Debug: main: radacctdir = "/var/log/freeradius/radacct" Wed May 9 17:51:58 2007 : Debug: main: hostname_lookups = no Wed May 9 17:51:58 2007 : Debug: main: max_request_time = 30 Wed May 9 17:51:58 2007 : Debug: main: cleanup_delay = 5 Wed May 9 17:51:58 2007 : Debug: main: max_requests = 1024 Wed May 9 17:51:58 2007 : Debug: main: delete_blocked_requests = 0 Wed May 9 17:51:58 2007 : Debug: main: port = 0 Wed May 9 17:51:58 2007 : Debug: main: allow_core_dumps = no Wed May 9 17:51:58 2007 : Debug: main: log_stripped_names = no Wed May 9 17:51:58 2007 : Debug: main: log_file = "/var/log/freeradius/radius.log" Wed May 9 17:51:58 2007 : Debug: main: log_auth = no Wed May 9 17:51:58 2007 : Debug: main: log_auth_badpass = no Wed May 9 17:51:58 2007 : Debug: main: log_auth_goodpass = no Wed May 9 17:51:58 2007 : Debug: main: pidfile = "/var/run/freeradius/freeradius.pid" Wed May 9 17:51:58 2007 : Debug: main: bind_address = 192.168.0.1 IP address [192.168.0.1] Wed May 9 17:51:58 2007 : Debug: main: user = "freerad" Wed May 9 17:51:58 2007 : Debug: main: group = "freerad" Wed May 9 17:51:58 2007 : Debug: main: usercollide = no Wed May 9 17:51:58 2007 : Debug: main: lower_user = "no" Wed May 9 17:51:58 2007 : Debug: main: lower_pass = "no" Wed May 9 17:51:58 2007 : Debug: main: nospace_user = "no" Wed May 9 17:51:58 2007 : Debug: main: nospace_pass = "no" Wed May 9 17:51:58 2007 : Debug: main: checkrad = "/usr/sbin/checkrad" Wed May 9 17:51:58 2007 : Debug: main: proxy_requests = yes Wed May 9 17:51:58 2007 : Debug: proxy: retry_delay = 5 Wed May 9 17:51:58 2007 : Debug: proxy: retry_count = 3 Wed May 9 17:51:58 2007 : Debug: proxy: synchronous = no Wed May 9 17:51:58 2007 : Debug: proxy: default_fallback = yes Wed May 9 17:51:58 2007 : Debug: proxy: dead_time = 120 Wed May 9 17:51:58 2007 : Debug: proxy: post_proxy_authorize = no Wed May 9 17:51:58 2007 : Debug: proxy: wake_all_if_all_dead = no Wed May 9 17:51:58 2007 : Debug: security: max_attributes = 200 Wed May 9 17:51:58 2007 : Debug: security: reject_delay = 1 Wed May 9 17:51:58 2007 : Debug: security: status_server = no Wed May 9 17:51:58 2007 : Debug: main: debug_level = 0 Wed May 9 17:51:58 2007 : Debug: read_config_files: reading dictionary Wed May 9 17:51:58 2007 : Debug: read_config_files: reading naslist Wed May 9 17:51:58 2007 : Info: Using deprecated naslist file. Support for this will go away soon. Wed May 9 17:51:58 2007 : Debug: read_config_files: reading clients Wed May 9 17:51:58 2007 : Debug: read_config_files: reading realms Wed May 9 17:51:58 2007 : Debug: radiusd: entering modules setup Wed May 9 17:51:58 2007 : Debug: Module: Library search path is /usr/lib/freeradius Wed May 9 17:51:58 2007 : Debug: Module: Loaded exec Wed May 9 17:51:58 2007 : Debug: exec: wait = yes Wed May 9 17:51:58 2007 : Debug: exec: program = "(null)" Wed May 9 17:51:58 2007 : Debug: exec: input_pairs = "request" Wed May 9 17:51:58 2007 : Debug: exec: output_pairs = "(null)" Wed May 9 17:51:58 2007 : Debug: exec: packet_type = "(null)" Wed May 9 17:51:58 2007 : Info: rlm_exec: Wait=yes but no output defined. Did you mean output=none? Wed May 9 17:51:58 2007 : Debug: Module: Instantiated exec (exec) Wed May 9 17:51:58 2007 : Debug: Module: Loaded expr Wed May 9 17:51:58 2007 : Debug: Module: Instantiated expr (expr) Wed May 9 17:51:58 2007 : Debug: Module: Loaded PAP Wed May 9 17:51:58 2007 : Debug: pap: encryption_scheme = "crypt" Wed May 9 17:51:58 2007 : Debug: Module: Instantiated pap (pap) Wed May 9 17:51:58 2007 : Debug: Module: Loaded CHAP Wed May 9 17:51:58 2007 : Debug: Module: Instantiated chap (chap) Wed May 9 17:51:58 2007 : Debug: Module: Loaded MS-CHAP Wed May 9 17:51:58 2007 : Debug: mschap: use_mppe = yes Wed May 9 17:51:58 2007 : Debug: mschap: require_encryption = yes Wed May 9 17:51:58 2007 : Debug: mschap: require_strong = yes Wed May 9 17:51:58 2007 : Debug: mschap: with_ntdomain_hack = no Wed May 9 17:51:58 2007 : Debug: mschap: passwd = "(null)" Wed May 9 17:51:58 2007 : Debug: mschap: ntlm_auth = "(null)" Wed May 9 17:51:58 2007 : Debug: Module: Instantiated mschap (mschap) Wed May 9 17:51:58 2007 : Debug: Module: Loaded eap Wed May 9 17:51:58 2007 : Debug: eap: default_eap_type = "peap" Wed May 9 17:51:58 2007 : Debug: eap: timer_expire = 60 Wed May 9 17:51:58 2007 : Debug: eap: ignore_unknown_eap_types = no Wed May 9 17:51:58 2007 : Debug: eap: cisco_accounting_username_bug = no Wed May 9 17:51:58 2007 : Debug: rlm_eap: Loaded and initialized type md5 Wed May 9 17:51:58 2007 : Debug: rlm_eap: Loaded and initialized type leap Wed May 9 17:51:58 2007 : Debug: tls: rsa_key_exchange = no Wed May 9 17:51:58 2007 : Debug: tls: dh_key_exchange = yes Wed May 9 17:51:58 2007 : Debug: tls: rsa_key_length = 512 Wed May 9 17:51:58 2007 : Debug: tls: dh_key_length = 512 Wed May 9 17:51:58 2007 : Debug: tls: verify_depth = 0 Wed May 9 17:51:58 2007 : Debug: tls: CA_path = "(null)" Wed May 9 17:51:58 2007 : Debug: tls: pem_file_type = yes Wed May 9 17:51:58 2007 : Debug: tls: private_key_file = "/etc/freeradius/certs/cert-srv.pem" Wed May 9 17:51:58 2007 : Debug: tls: certificate_file = "/etc/freeradius/certs/cert-srv.pem" Wed May 9 17:51:58 2007 : Debug: tls: CA_file = "/etc/freeradius/certs/demoCA/cacert.pem" Wed May 9 17:51:58 2007 : Debug: tls: private_key_password = "whatever" Wed May 9 17:51:58 2007 : Debug: tls: dh_file = "/etc/freeradius/certs/dh" Wed May 9 17:51:58 2007 : Debug: tls: random_file = "/etc/freeradius/certs/random" Wed May 9 17:51:58 2007 : Debug: tls: fragment_size = 1024 Wed May 9 17:51:58 2007 : Debug: tls: include_length = yes Wed May 9 17:51:58 2007 : Debug: tls: check_crl = no Wed May 9 17:51:58 2007 : Debug: tls: check_cert_cn = "(null)" Wed May 9 17:51:58 2007 : Debug: tls: cipher_list = "(null)" Wed May 9 17:51:58 2007 : Debug: tls: check_cert_issuer = "(null)" Wed May 9 17:51:58 2007 : Info: rlm_eap_tls: Loading the certificate file as a chain Wed May 9 17:51:58 2007 : Debug: rlm_eap: Loaded and initialized type tls Wed May 9 17:51:58 2007 : Debug: peap: default_eap_type = "mschapv2" Wed May 9 17:51:58 2007 : Debug: peap: copy_request_to_tunnel = no Wed May 9 17:51:58 2007 : Debug: peap: use_tunneled_reply = yes Wed May 9 17:51:58 2007 : Debug: peap: proxy_tunneled_request_as_eap = yes Wed May 9 17:51:58 2007 : Debug: rlm_eap: Loaded and initialized type peap Wed May 9 17:51:58 2007 : Debug: mschapv2: with_ntdomain_hack = no Wed May 9 17:51:58 2007 : Debug: rlm_eap: Loaded and initialized type mschapv2 Wed May 9 17:51:58 2007 : Debug: Module: Instantiated eap (eap) Wed May 9 17:51:58 2007 : Debug: Module: Loaded preprocess Wed May 9 17:51:58 2007 : Debug: preprocess: huntgroups = "/etc/freeradius/huntgroups" Wed May 9 17:51:58 2007 : Debug: preprocess: hints = "/etc/freeradius/hints" Wed May 9 17:51:58 2007 : Debug: preprocess: with_ascend_hack = no Wed May 9 17:51:58 2007 : Debug: preprocess: ascend_channels_per_line = 23 Wed May 9 17:51:58 2007 : Debug: preprocess: with_ntdomain_hack = no Wed May 9 17:51:58 2007 : Debug: preprocess: with_specialix_jetstream_hack = no Wed May 9 17:51:58 2007 : Debug: preprocess: with_cisco_vsa_hack = no Wed May 9 17:51:58 2007 : Debug: preprocess: with_alvarion_vsa_hack = no Wed May 9 17:51:58 2007 : Debug: Module: Instantiated preprocess (preprocess) Wed May 9 17:51:58 2007 : Debug: Module: Loaded realm Wed May 9 17:51:58 2007 : Debug: realm: format = "suffix" Wed May 9 17:51:58 2007 : Debug: realm: delimiter = "@" Wed May 9 17:51:58 2007 : Debug: realm: ignore_default = no Wed May 9 17:51:58 2007 : Debug: realm: ignore_null = no Wed May 9 17:51:58 2007 : Debug: Module: Instantiated realm (suffix) Wed May 9 17:51:58 2007 : Debug: Module: Loaded SQL Wed May 9 17:51:58 2007 : Debug: sql: driver = "rlm_sql_mysql" Wed May 9 17:51:58 2007 : Debug: sql: server = "localhost" Wed May 9 17:51:58 2007 : Debug: sql: port = "" Wed May 9 17:51:58 2007 : Debug: sql: login = "radius" Wed May 9 17:51:58 2007 : Debug: sql: password = "cisonline" Wed May 9 17:51:58 2007 : Debug: sql: radius_db = "radius" Wed May 9 17:51:58 2007 : Debug: sql: nas_table = "nas" Wed May 9 17:51:58 2007 : Debug: sql: sqltrace = no Wed May 9 17:51:58 2007 : Debug: sql: sqltracefile = "/var/log/freeradius/sqltrace.sql" Wed May 9 17:51:58 2007 : Debug: sql: readclients = no Wed May 9 17:51:58 2007 : Debug: sql: deletestalesessions = yes Wed May 9 17:51:58 2007 : Debug: sql: num_sql_socks = 5 Wed May 9 17:51:58 2007 : Debug: sql: sql_user_name = "%{User-Name}" Wed May 9 17:51:58 2007 : Debug: sql: default_user_profile = "" Wed May 9 17:51:58 2007 : Debug: sql: query_on_not_found = no Wed May 9 17:51:58 2007 : Debug: sql: authorize_check_query = "SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id" Wed May 9 17:51:58 2007 : Debug: sql: authorize_reply_query = "SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id" Wed May 9 17:51:58 2007 : Debug: 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" Wed May 9 17:51:58 2007 : Debug: 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" Wed May 9 17:51:58 2007 : Debug: 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'" Wed May 9 17:51:58 2007 : Debug: 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}'" Wed May 9 17:51:58 2007 : Debug: 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')" Wed May 9 17:51:58 2007 : Debug: 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')" Wed May 9 17:51:58 2007 : Debug: 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}'" Wed May 9 17:51:58 2007 : Debug: 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}'" Wed May 9 17:51:58 2007 : Debug: 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}')" Wed May 9 17:51:58 2007 : Debug: sql: group_membership_query = "SELECT GroupName FROM usergroup WHERE UserName='%{SQL-User-Name}'" Wed May 9 17:51:58 2007 : Debug: sql: connect_failure_retry_delay = 60 Wed May 9 17:51:58 2007 : Debug: sql: simul_count_query = "" Wed May 9 17:51:58 2007 : Debug: sql: simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime = 0" Wed May 9 17:51:58 2007 : Debug: sql: postauth_query = "INSERT into radpostauth (id, user, pass, reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW())" Wed May 9 17:51:58 2007 : Debug: sql: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Wed May 9 17:51:58 2007 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Wed May 9 17:51:58 2007 : Info: rlm_sql (sql): Attempting to connect to radius@localhost:/radius Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): starting 0 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 Wed May 9 17:51:58 2007 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Connected new DB handle, #0 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): starting 1 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 Wed May 9 17:51:58 2007 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Connected new DB handle, #1 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): starting 2 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 Wed May 9 17:51:58 2007 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Connected new DB handle, #2 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): starting 3 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 Wed May 9 17:51:58 2007 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Connected new DB handle, #3 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): starting 4 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 Wed May 9 17:51:58 2007 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Wed May 9 17:51:58 2007 : Debug: rlm_sql (sql): Connected new DB handle, #4 Wed May 9 17:51:58 2007 : Debug: Module: Instantiated sql (sql) Wed May 9 17:51:58 2007 : Debug: Module: Loaded Acct-Unique-Session-Id Wed May 9 17:51:58 2007 : Debug: acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Wed May 9 17:51:58 2007 : Debug: Module: Instantiated acct_unique (acct_unique) Wed May 9 17:51:58 2007 : Debug: Module: Loaded detail Wed May 9 17:51:58 2007 : Debug: detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Wed May 9 17:51:58 2007 : Debug: detail: detailperm = 384 Wed May 9 17:51:58 2007 : Debug: detail: dirperm = 493 Wed May 9 17:51:58 2007 : Debug: detail: locking = no Wed May 9 17:51:58 2007 : Debug: Module: Instantiated detail (detail) Wed May 9 17:51:58 2007 : Debug: Module: Loaded System Wed May 9 17:51:58 2007 : Debug: unix: cache = no Wed May 9 17:51:58 2007 : Debug: unix: passwd = "(null)" Wed May 9 17:51:58 2007 : Debug: unix: shadow = "/etc/shadow" Wed May 9 17:51:58 2007 : Debug: unix: group = "(null)" Wed May 9 17:51:58 2007 : Debug: unix: radwtmp = "/var/log/freeradius/radwtmp" Wed May 9 17:51:58 2007 : Debug: unix: usegroup = no Wed May 9 17:51:58 2007 : Debug: unix: cache_reload = 600 Wed May 9 17:51:58 2007 : Debug: Module: Instantiated unix (unix) Wed May 9 17:51:58 2007 : Debug: Module: Loaded radutmp Wed May 9 17:51:58 2007 : Debug: radutmp: filename = "/var/log/freeradius/radutmp" Wed May 9 17:51:58 2007 : Debug: radutmp: username = "%{User-Name}" Wed May 9 17:51:58 2007 : Debug: radutmp: case_sensitive = yes Wed May 9 17:51:58 2007 : Debug: radutmp: check_with_nas = yes Wed May 9 17:51:58 2007 : Debug: radutmp: perm = 384 Wed May 9 17:51:58 2007 : Debug: radutmp: callerid = yes Wed May 9 17:51:58 2007 : Debug: Module: Instantiated radutmp (radutmp) Wed May 9 17:51:58 2007 : Debug: Listening on authentication 192.168.0.1:1812 Wed May 9 17:51:58 2007 : Debug: Listening on accounting 192.168.0.1:1813 Wed May 9 17:51:58 2007 : Info: Ready to process requests. rad_recv: Access-Request packet from host 192.168.0.254:1039, id=71, length=201 Framed-MTU = 1480 NAS-IP-Address = 172.17.1.10 NAS-Identifier = "CIS2650" User-Name = "david" Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 39 NAS-Port-Type = Ethernet NAS-Port-Id = "39" Called-Station-Id = "00-19-bb-6a-2d-80" Calling-Station-Id = "00-11-25-d6-ab-1a" Connect-Info = "CONNECT Ethernet 100Mbps Full duplex" Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3" EAP-Message = 0x0201000c0170726174657369 Message-Authenticator = 0x0bce6099ad4417ee86a75d1549a6b2f2 Wed May 9 17:54:37 2007 : Debug: Processing the authorize section of radiusd.conf Wed May 9 17:54:37 2007 : Debug: modcall: entering group authorize for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 0 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 0 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 0 Wed May 9 17:54:37 2007 : Debug: rlm_realm: No '@' in User-Name = "david", looking up realm NULL Wed May 9 17:54:37 2007 : Debug: rlm_realm: No such realm "NULL" Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 0 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0 Wed May 9 17:54:37 2007 : Debug: rlm_eap: EAP packet type response id 1 length 12 Wed May 9 17:54:37 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling sql (rlm_sql) for request 0 Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'david' Wed May 9 17:54:37 2007 : Debug: rlm_sql (sql): sql_set_user escaped user --> 'david' Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'david' ORDER BY id' Wed May 9 17:54:37 2007 : Debug: rlm_sql (sql): Reserving sql socket id: 4 Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'david' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'david' ORDER BY id' Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'david' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' Wed May 9 17:54:37 2007 : Debug: rlm_sql (sql): Released sql socket id: 4 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from sql (rlm_sql) for request 0 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "sql" returns ok for request 0 Wed May 9 17:54:37 2007 : Debug: modcall: leaving group authorize (returns updated) for request 0 Wed May 9 17:54:37 2007 : Debug: rad_check_password: Found Auth-Type EAP Wed May 9 17:54:37 2007 : Debug: auth: type "EAP" Wed May 9 17:54:37 2007 : Debug: Processing the authenticate section of radiusd.conf Wed May 9 17:54:37 2007 : Debug: modcall: entering group authenticate for request 0 Wed May 9 17:54:37 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 0 Wed May 9 17:54:37 2007 : Debug: rlm_eap: EAP Identity Wed May 9 17:54:37 2007 : Debug: rlm_eap: processing type tls Wed May 9 17:54:37 2007 : Debug: rlm_eap_tls: Initiate Wed May 9 17:54:37 2007 : Debug: rlm_eap_tls: Start returned 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 0 Wed May 9 17:54:37 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 0 Wed May 9 17:54:37 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 0 Sending Access-Challenge of id 71 to 192.168.0.254 port 1039 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "1" EAP-Message = 0x010200061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1d29dc63e3727a27017d56d212ebbe51 Wed May 9 17:54:37 2007 : Debug: Finished request 0 Wed May 9 17:54:37 2007 : Debug: Going to the next request Wed May 9 17:54:37 2007 : Debug: --- Walking the entire request list --- Wed May 9 17:54:37 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.0.254:1039, id=72, length=287 Framed-MTU = 1480 NAS-IP-Address = 172.17.1.10 NAS-Identifier = "CIS2650" User-Name = "david" Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 39 NAS-Port-Type = Ethernet NAS-Port-Id = "39" Called-Station-Id = "00-19-bb-6a-2d-80" Calling-Station-Id = "00-11-25-d6-ab-1a" Connect-Info = "CONNECT Ethernet 100Mbps Full duplex" Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3" State = 0x1d29dc63e3727a27017d56d212ebbe51 EAP-Message = 0x0202005019800000004616030100410100003d03014641eeacad5de1cf91cb82312b724ce969405f00152ecb9fe36317d9e794505500001600040005000a000900640062000300060013001200630100 Message-Authenticator = 0x848b664f7ebf5d0c45b92e1ea6dcbf29 Wed May 9 17:54:37 2007 : Debug: Processing the authorize section of radiusd.conf Wed May 9 17:54:37 2007 : Debug: modcall: entering group authorize for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 1 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 1 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 1 Wed May 9 17:54:37 2007 : Debug: rlm_realm: No '@' in User-Name = "david", looking up realm NULL Wed May 9 17:54:37 2007 : Debug: rlm_realm: No such realm "NULL" Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 1 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 1 Wed May 9 17:54:37 2007 : Debug: rlm_eap: EAP packet type response id 2 length 80 Wed May 9 17:54:37 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 1 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: calling sql (rlm_sql) for request 1 Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'david' Wed May 9 17:54:37 2007 : Debug: rlm_sql (sql): sql_set_user escaped user --> 'david' Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'david' ORDER BY id' Wed May 9 17:54:37 2007 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'david' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'david' ORDER BY id' Wed May 9 17:54:37 2007 : Debug: radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'david' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' Wed May 9 17:54:37 2007 : Debug: rlm_sql (sql): Released sql socket id: 3 Wed May 9 17:54:37 2007 : Debug: modsingle[authorize]: returned from sql (rlm_sql) for request 1 Wed May 9 17:54:37 2007 : Debug: modcall[authorize]: module "sql" returns ok for request 1 Wed May 9 17:54:37 2007 : Debug: modcall: leaving group authorize (returns updated) for request 1 Wed May 9 17:54:37 2007 : Debug: rad_check_password: Found Auth-Type EAP Wed May 9 17:54:37 2007 : Debug: auth: type "EAP" Wed May 9 17:54:37 2007 : Debug: Processing the authenticate section of radiusd.conf Wed May 9 17:54:37 2007 : Debug: modcall: entering group authenticate for request 1 Wed May 9 17:54:37 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 1 Wed May 9 17:54:37 2007 : Debug: rlm_eap: Request found, released from the list Wed May 9 17:54:37 2007 : Debug: rlm_eap: EAP/peap Wed May 9 17:54:37 2007 : Debug: rlm_eap: processing type peap Wed May 9 17:54:37 2007 : Debug: rlm_eap_peap: Authenticate Wed May 9 17:54:37 2007 : Debug: rlm_eap_tls: processing TLS Wed May 9 17:54:37 2007 : Debug: rlm_eap_tls: Length Included Wed May 9 17:54:37 2007 : Debug: eaptls_verify returned 11 Wed May 9 17:54:37 2007 : Debug: (other): before/accept initialization Wed May 9 17:54:37 2007 : Debug: TLS_accept: before/accept initialization Wed May 9 17:54:37 2007 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0041], ClientHello Wed May 9 17:54:37 2007 : Debug: TLS_accept: SSLv3 read client hello A Wed May 9 17:54:37 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello Wed May 9 17:54:37 2007 : Debug: TLS_accept: SSLv3 write server hello A Wed May 9 17:54:37 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0346], Certificate Wed May 9 17:54:37 2007 : Debug: TLS_accept: SSLv3 write certificate A Wed May 9 17:54:37 2007 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Wed May 9 17:54:37 2007 : Debug: TLS_accept: SSLv3 write server done A Wed May 9 17:54:37 2007 : Debug: TLS_accept: SSLv3 flush data Wed May 9 17:54:37 2007 : Error: TLS_accept:error in SSLv3 read client certificate A Wed May 9 17:54:37 2007 : Error: rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0) Wed May 9 17:54:37 2007 : Debug: In SSL Handshake Phase Wed May 9 17:54:37 2007 : Debug: In SSL Accept mode Wed May 9 17:54:37 2007 : Debug: eaptls_process returned 13 Wed May 9 17:54:37 2007 : Debug: rlm_eap_peap: EAPTLS_HANDLED Wed May 9 17:54:37 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 1 Wed May 9 17:54:37 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 1 Wed May 9 17:54:37 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 1 Sending Access-Challenge of id 72 to 192.168.0.254 port 1039 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "1" EAP-Message = 0x010303a91900160301004a0200004603014641eebd4b0257f30568312508ce9d844da2ab8cdbc40e8bbfc011c7854f405e20d80a80e573f163f60573e9abfe1cf11719e3ebf6f8aa6607cac262017cc3521f00040016030103460b00034200033f00033c3082033830820220a003020102020102300d06092a864886f70d01010505003053310b3009060355040613024155311330110603550408130a536f6d652d53746174653121301f060355040a1318496e7465726e6574205769646769747320507479204c7464310c300a06035504031303636973301e170d3037303530333038303232355a170d3038303530323038303232355a3053310b30 EAP-Message = 0x09060355040613024155311330110603550408130a536f6d652d53746174653121301f060355040a1318496e7465726e6574205769646769747320507479204c7464310c300a0603550403130363697330820122300d06092a864886f70d01010105000382010f003082010a0282010100be1f23b9bf021191c28df0d121a868f37aa0ed8650dfd3525c9bfd9782dd4528e7f670981ee608eb3c3b01334cff4532b4b59b3b132e71abdf2634bf00fc7234404f255291e3888816de19ea9c80b283a52d0f8cace67230d172f7ddcea6e0bd6793924b5d1c98c7cb80ea60f9a9b97757bf90420dcd25ddb79a500f4ef79f59dd0ae5b81fb6522f8d042a31 EAP-Message = 0x6d2f0720a8dc00f73ad27bc737294cac8eeb7c914a7afa577c1532e34712f752a7a77e65e45350cf88a9d366f4d9bcc9ff4bb7611938a20f8534655fbfe0d205ef65eb408c91e3b1988d19144227aa8081ddcc94854619e0daadc64e0460d18ccaff05ac3163c3ca681aff1fcb62bab71a771a230203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000382010100339dc8986a5c60e942fcf5e76230fde8b3e75d73a8fc182512262617ec74b358d20452512e25bfc44d594cfaa100674207adb9f267d369ff7d5a6deb558b7cbd538aa5ccd4b44030be51acde4dc3ac940ec4c37335f277 EAP-Message = 0x5246554e7c031fd501578b605daa683c51c0d38c12b48f088b2360a2bd6f4ae8edaf53617335befcb7e3eafe8c99e6adcd944b9e6da0a21acb056763d11b6e32a53d6bb3bb93d6dbfb8cc373f07f6efb2e9cf38ced2b04a43af28a00432d3bd936276b26a0f66540af127ed392a6cd83b89626ddcad0c090af2f239e05127baf8df9659dba0f0280415a9a6569c23dcbc22f3c2a2922826f56e5b1bd90f2a4c979ac2e52efb019932e16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xc5018df96803d9ee44a6047b590c6057 Wed May 9 17:54:37 2007 : Debug: Finished request 1 Wed May 9 17:54:37 2007 : Debug: Going to the next request Wed May 9 17:54:37 2007 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.0.254:1039, id=73, length=213 Framed-MTU = 1480 NAS-IP-Address = 172.17.1.10 NAS-Identifier = "CIS2650" User-Name = "david" Service-Type = Framed-User Framed-Protocol = PPP NAS-Port = 39 NAS-Port-Type = Ethernet NAS-Port-Id = "39" Called-Station-Id = "00-19-bb-6a-2d-80" Calling-Station-Id = "00-11-25-d6-ab-1a" Connect-Info = "CONNECT Ethernet 100Mbps Full duplex" Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3" State = 0xc5018df96803d9ee44a6047b590c6057 EAP-Message = 0x020300061900 Message-Authenticator = 0x1ada415bcaa4a23684361400292abc59 Wed May 9 17:54:38 2007 : Debug: Processing the authorize section of radiusd.conf Wed May 9 17:54:38 2007 : Debug: modcall: entering group authorize for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2 Wed May 9 17:54:38 2007 : Debug: modcall[authorize]: module "preprocess" returns ok for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 2 Wed May 9 17:54:38 2007 : Debug: modcall[authorize]: module "chap" returns noop for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 2 Wed May 9 17:54:38 2007 : Debug: modcall[authorize]: module "mschap" returns noop for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 2 Wed May 9 17:54:38 2007 : Debug: rlm_realm: No '@' in User-Name = "david", looking up realm NULL Wed May 9 17:54:38 2007 : Debug: rlm_realm: No such realm "NULL" Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 2 Wed May 9 17:54:38 2007 : Debug: modcall[authorize]: module "suffix" returns noop for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 2 Wed May 9 17:54:38 2007 : Debug: rlm_eap: EAP packet type response id 3 length 6 Wed May 9 17:54:38 2007 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 2 Wed May 9 17:54:38 2007 : Debug: modcall[authorize]: module "eap" returns updated for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: calling sql (rlm_sql) for request 2 Wed May 9 17:54:38 2007 : Debug: radius_xlat: 'david' Wed May 9 17:54:38 2007 : Debug: rlm_sql (sql): sql_set_user escaped user --> 'david' Wed May 9 17:54:38 2007 : Debug: radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'david' ORDER BY id' Wed May 9 17:54:38 2007 : Debug: rlm_sql (sql): Reserving sql socket id: 2 Wed May 9 17:54:38 2007 : Debug: radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'david' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' Wed May 9 17:54:38 2007 : Debug: radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'david' ORDER BY id' Wed May 9 17:54:38 2007 : Debug: radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'david' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' Wed May 9 17:54:38 2007 : Debug: rlm_sql (sql): Released sql socket id: 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authorize]: returned from sql (rlm_sql) for request 2 Wed May 9 17:54:38 2007 : Debug: modcall[authorize]: module "sql" returns ok for request 2 Wed May 9 17:54:38 2007 : Debug: modcall: leaving group authorize (returns updated) for request 2 Wed May 9 17:54:38 2007 : Debug: rad_check_password: Found Auth-Type EAP Wed May 9 17:54:38 2007 : Debug: auth: type "EAP" Wed May 9 17:54:38 2007 : Debug: Processing the authenticate section of radiusd.conf Wed May 9 17:54:38 2007 : Debug: modcall: entering group authenticate for request 2 Wed May 9 17:54:38 2007 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 2 Wed May 9 17:54:38 2007 : Debug: rlm_eap: Request found, released from the list Wed May 9 17:54:38 2007 : Debug: rlm_eap: EAP/peap Wed May 9 17:54:38 2007 : Debug: rlm_eap: processing type peap Wed May 9 17:54:38 2007 : Debug: rlm_eap_peap: Authenticate Wed May 9 17:54:38 2007 : Debug: rlm_eap_tls: processing TLS Wed May 9 17:54:38 2007 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Wed May 9 17:54:38 2007 : Debug: rlm_eap_tls: ack handshake fragment handler Wed May 9 17:54:38 2007 : Debug: eaptls_verify returned 1 Wed May 9 17:54:38 2007 : Debug: eaptls_process returned 13 Wed May 9 17:54:38 2007 : Debug: rlm_eap_peap: EAPTLS_HANDLED Wed May 9 17:54:38 2007 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 2 Wed May 9 17:54:38 2007 : Debug: modcall[authenticate]: module "eap" returns handled for request 2 Wed May 9 17:54:38 2007 : Debug: modcall: leaving group authenticate (returns handled) for request 2 Sending Access-Challenge of id 73 to 192.168.0.254 port 1039 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "1" EAP-Message = 0x010400061900 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xe7a8882c93b992e5d2c3b9eab695e62a Wed May 9 17:54:38 2007 : Debug: Finished request 2 Wed May 9 17:54:38 2007 : Debug: Going to the next request Wed May 9 17:54:38 2007 : Debug: --- Walking the entire request list --- Wed May 9 17:54:38 2007 : Debug: Waking up in 5 seconds... Wed May 9 17:54:43 2007 : Debug: --- Walking the entire request list --- Wed May 9 17:54:43 2007 : Debug: Cleaning up request 0 ID 71 with timestamp 4641eebd Wed May 9 17:54:43 2007 : Debug: Cleaning up request 1 ID 72 with timestamp 4641eebd Wed May 9 17:54:43 2007 : Debug: Waking up in 1 seconds... Wed May 9 17:54:44 2007 : Debug: --- Walking the entire request list --- Wed May 9 17:54:44 2007 : Debug: Cleaning up request 2 ID 73 with timestamp 4641eebe Wed May 9 17:54:44 2007 : Debug: Nothing to do. Sleeping until we see a request. david _________________________________________________________________ Personalizza la tua casella di posta con Windows Live Hotmail! http://imagine-windowslive.com/hotmail/default.aspx?locale=it#5