Problems with PEAP
pippo metallaro
shyboy at hotmail.it
Thu May 10 15:05:58 CEST 2007
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 at 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
More information about the Freeradius-Users
mailing list