Error: rlm_eap: No EAP session matching the State variable.
Rupesh Kumar
a.rupesh.k at gmail.com
Mon Apr 12 06:37:26 CEST 2010
Hi,
I am using latest freeradius server (version 2.1.8).
I have two authenticated sessions established with radius server and when
disable and reenable the dot1x sessions, then I am seeing the following
error and one request is getting Reject message from the server.
Info: Found Auth-Type = EAP
Info: +- entering group authenticate {...}
Error: rlm_eap: No EAP session matching the State variable.
Info: [eap] Either EAP-request timed out OR EAP-response to an unknown
EAP-request
Info: [eap] Failed in handler
Info: ++[eap] returns invalid
I have seen the archive and found there are some old issues related to this
error.
Is it a known issue in radius server or what is the root cause of it.
I have attached radius server failure log messages
Thanks in advance !
Cheers
Rupesh
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20100412/d483f8d2/attachment.html>
-------------- next part --------------
Fri Apr 9 05:12:31 2010 : Info: FreeRADIUS Version 2.1.6, for host i686-pc-linux-gnu, built on Sep 12 2009 at 16:50:08
Fri Apr 9 05:12:31 2010 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.
Fri Apr 9 05:12:31 2010 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Fri Apr 9 05:12:31 2010 : Info: PARTICULAR PURPOSE.
Fri Apr 9 05:12:31 2010 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Fri Apr 9 05:12:31 2010 : Info: GNU General Public License v2.
Fri Apr 9 05:12:31 2010 : Info: Starting - reading configuration files ...
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/radiusd.conf
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/proxy.conf
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/clients.conf
Fri Apr 9 05:12:31 2010 : Debug: including files in directory /usr/local/etc/raddb/modules/
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/radutmp
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/checkval
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/otp
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/ippool
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/pap
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/unix
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/files
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.log
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/realm
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/smsotp
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/wimax
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/smbpasswd
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/inner-eap
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.example.com
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/perl
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/exec
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/sql_log
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/always
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/echo
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/krb5
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2ip
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/counter
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/policy
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/logintime
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/acct_unique
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_filter
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_rewrite
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/expiration
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/mschap
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/passwd
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/linelog
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/expr
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/digest
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/sradutmp
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2vlan
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/pam
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/etc_group
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/detail
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/ldap
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/preprocess
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/chap
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/eap.conf
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/policy.conf
Fri Apr 9 05:12:31 2010 : Debug: including files in directory /usr/local/etc/raddb/sites-enabled/
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/control-socket
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel
Fri Apr 9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/default
Fri Apr 9 05:12:31 2010 : Debug: including dictionary file /usr/local/etc/raddb/dictionary
Fri Apr 9 05:12:31 2010 : Debug: main {
Fri Apr 9 05:12:31 2010 : Debug: prefix = "/usr/local"
Fri Apr 9 05:12:31 2010 : Debug: localstatedir = "/usr/local/var"
Fri Apr 9 05:12:31 2010 : Debug: logdir = "/usr/local/var/log/radius"
Fri Apr 9 05:12:31 2010 : Debug: libdir = "/usr/local/lib"
Fri Apr 9 05:12:31 2010 : Debug: radacctdir = "/usr/local/var/log/radius/radacct"
Fri Apr 9 05:12:31 2010 : Debug: hostname_lookups = no
Fri Apr 9 05:12:31 2010 : Debug: max_request_time = 30
Fri Apr 9 05:12:31 2010 : Debug: cleanup_delay = 5
Fri Apr 9 05:12:31 2010 : Debug: max_requests = 1024
Fri Apr 9 05:12:31 2010 : Debug: allow_core_dumps = no
Fri Apr 9 05:12:31 2010 : Debug: pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
Fri Apr 9 05:12:31 2010 : Debug: checkrad = "/usr/local/sbin/checkrad"
Fri Apr 9 05:12:31 2010 : Debug: debug_level = 0
Fri Apr 9 05:12:31 2010 : Debug: proxy_requests = yes
Fri Apr 9 05:12:31 2010 : Debug: log {
Fri Apr 9 05:12:31 2010 : Debug: stripped_names = no
Fri Apr 9 05:12:31 2010 : Debug: auth = no
Fri Apr 9 05:12:31 2010 : Debug: auth_badpass = no
Fri Apr 9 05:12:31 2010 : Debug: auth_goodpass = no
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: security {
Fri Apr 9 05:12:31 2010 : Debug: max_attributes = 200
Fri Apr 9 05:12:31 2010 : Debug: reject_delay = 1
Fri Apr 9 05:12:31 2010 : Debug: status_server = yes
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: radiusd: #### Loading Realms and Home Servers ####
Fri Apr 9 05:12:31 2010 : Debug: proxy server {
Fri Apr 9 05:12:31 2010 : Debug: retry_delay = 5
Fri Apr 9 05:12:31 2010 : Debug: retry_count = 3
Fri Apr 9 05:12:31 2010 : Debug: default_fallback = no
Fri Apr 9 05:12:31 2010 : Debug: dead_time = 120
Fri Apr 9 05:12:31 2010 : Debug: wake_all_if_all_dead = no
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: home_server localhost {
Fri Apr 9 05:12:31 2010 : Debug: ipaddr = 127.0.0.1
Fri Apr 9 05:12:31 2010 : Debug: port = 1812
Fri Apr 9 05:12:31 2010 : Debug: type = "auth"
Fri Apr 9 05:12:31 2010 : Debug: secret = "testing123"
Fri Apr 9 05:12:31 2010 : Debug: response_window = 20
Fri Apr 9 05:12:31 2010 : Debug: max_outstanding = 65536
Fri Apr 9 05:12:31 2010 : Debug: require_message_authenticator = no
Fri Apr 9 05:12:31 2010 : Debug: zombie_period = 40
Fri Apr 9 05:12:31 2010 : Debug: status_check = "status-server"
Fri Apr 9 05:12:31 2010 : Debug: ping_interval = 30
Fri Apr 9 05:12:31 2010 : Debug: check_interval = 30
Fri Apr 9 05:12:31 2010 : Debug: num_answers_to_alive = 3
Fri Apr 9 05:12:31 2010 : Debug: num_pings_to_alive = 3
Fri Apr 9 05:12:31 2010 : Debug: revive_interval = 120
Fri Apr 9 05:12:31 2010 : Debug: status_check_timeout = 4
Fri Apr 9 05:12:31 2010 : Debug: irt = 2
Fri Apr 9 05:12:31 2010 : Debug: mrt = 16
Fri Apr 9 05:12:31 2010 : Debug: mrc = 5
Fri Apr 9 05:12:31 2010 : Debug: mrd = 30
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: home_server_pool my_auth_failover {
Fri Apr 9 05:12:31 2010 : Debug: type = fail-over
Fri Apr 9 05:12:31 2010 : Debug: home_server = localhost
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: realm example.com {
Fri Apr 9 05:12:31 2010 : Debug: auth_pool = my_auth_failover
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: realm LOCAL {
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: radiusd: #### Loading Clients ####
Fri Apr 9 05:12:31 2010 : Debug: client localhost {
Fri Apr 9 05:12:31 2010 : Debug: ipaddr = 127.0.0.1
Fri Apr 9 05:12:31 2010 : Debug: require_message_authenticator = no
Fri Apr 9 05:12:31 2010 : Debug: secret = "testing123"
Fri Apr 9 05:12:31 2010 : Debug: nastype = "other"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: client 10.32.49.91 {
Fri Apr 9 05:12:31 2010 : Debug: ipaddr = 10.32.49.91
Fri Apr 9 05:12:31 2010 : Debug: require_message_authenticator = no
Fri Apr 9 05:12:31 2010 : Debug: secret = "password"
Fri Apr 9 05:12:31 2010 : Debug: shortname = "switch"
Fri Apr 9 05:12:31 2010 : Debug: nastype = "other"
Fri Apr 9 05:12:31 2010 : Debug: login = "testuser"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: client 10.32.49.92 {
Fri Apr 9 05:12:31 2010 : Debug: ipaddr = 10.32.49.92
Fri Apr 9 05:12:31 2010 : Debug: require_message_authenticator = no
Fri Apr 9 05:12:31 2010 : Debug: secret = "password"
Fri Apr 9 05:12:31 2010 : Debug: shortname = "switch"
Fri Apr 9 05:12:31 2010 : Debug: nastype = "other"
Fri Apr 9 05:12:31 2010 : Debug: login = "testuser"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: client 10.32.49.88 {
Fri Apr 9 05:12:31 2010 : Debug: ipaddr = 10.32.49.88
Fri Apr 9 05:12:31 2010 : Debug: require_message_authenticator = no
Fri Apr 9 05:12:31 2010 : Debug: secret = "password"
Fri Apr 9 05:12:31 2010 : Debug: shortname = "switch"
Fri Apr 9 05:12:31 2010 : Debug: nastype = "other"
Fri Apr 9 05:12:31 2010 : Debug: login = "testuser"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: client 10.32.57.100 {
Fri Apr 9 05:12:31 2010 : Debug: ipaddr = 10.32.57.100
Fri Apr 9 05:12:31 2010 : Debug: require_message_authenticator = no
Fri Apr 9 05:12:31 2010 : Debug: secret = "password"
Fri Apr 9 05:12:31 2010 : Debug: shortname = "switch"
Fri Apr 9 05:12:31 2010 : Debug: nastype = "other"
Fri Apr 9 05:12:31 2010 : Debug: login = "testuser"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: client 10.37.18.108 {
Fri Apr 9 05:12:31 2010 : Debug: ipaddr = 10.37.18.108
Fri Apr 9 05:12:31 2010 : Debug: require_message_authenticator = no
Fri Apr 9 05:12:31 2010 : Debug: secret = "sharedsecret"
Fri Apr 9 05:12:31 2010 : Debug: shortname = "switch"
Fri Apr 9 05:12:31 2010 : Debug: nastype = "other"
Fri Apr 9 05:12:31 2010 : Debug: login = "testuser"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: radiusd: #### Instantiating modules ####
Fri Apr 9 05:12:31 2010 : Debug: instantiate {
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_exec, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_exec
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating exec
Fri Apr 9 05:12:31 2010 : Debug: exec {
Fri Apr 9 05:12:31 2010 : Debug: wait = no
Fri Apr 9 05:12:31 2010 : Debug: input_pairs = "request"
Fri Apr 9 05:12:31 2010 : Debug: shell_escape = yes
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_expr, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_expr
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating expr
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_expiration, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_expiration
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating expiration
Fri Apr 9 05:12:31 2010 : Debug: expiration {
Fri Apr 9 05:12:31 2010 : Debug: reply-message = "Password Has Expired "
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_logintime, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_logintime
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating logintime
Fri Apr 9 05:12:31 2010 : Debug: logintime {
Fri Apr 9 05:12:31 2010 : Debug: reply-message = "You are calling outside your allowed timespan "
Fri Apr 9 05:12:31 2010 : Debug: minimum-timeout = 60
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Apr 9 05:12:31 2010 : Debug: server inner-tunnel {
Fri Apr 9 05:12:31 2010 : Debug: modules {
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking authenticate {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_pap, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_pap
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating pap
Fri Apr 9 05:12:31 2010 : Debug: pap {
Fri Apr 9 05:12:31 2010 : Debug: encryption_scheme = "auto"
Fri Apr 9 05:12:31 2010 : Debug: auto_header = no
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_chap, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_chap
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating chap
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_mschap, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_mschap
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating mschap
Fri Apr 9 05:12:31 2010 : Debug: mschap {
Fri Apr 9 05:12:31 2010 : Debug: use_mppe = yes
Fri Apr 9 05:12:31 2010 : Debug: require_encryption = no
Fri Apr 9 05:12:31 2010 : Debug: require_strong = no
Fri Apr 9 05:12:31 2010 : Debug: with_ntdomain_hack = no
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_unix, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_unix
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating unix
Fri Apr 9 05:12:31 2010 : Debug: unix {
Fri Apr 9 05:12:31 2010 : Debug: radwtmp = "/usr/local/var/log/radius/radwtmp"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_eap, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_eap
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating eap
Fri Apr 9 05:12:31 2010 : Debug: eap {
Fri Apr 9 05:12:31 2010 : Debug: default_eap_type = "peap"
Fri Apr 9 05:12:31 2010 : Debug: timer_expire = 60
Fri Apr 9 05:12:31 2010 : Debug: ignore_unknown_eap_types = no
Fri Apr 9 05:12:31 2010 : Debug: cisco_accounting_username_bug = no
Fri Apr 9 05:12:31 2010 : Debug: max_sessions = 2048
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to sub-module rlm_eap_md5
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating eap-md5
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to sub-module rlm_eap_leap
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating eap-leap
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to sub-module rlm_eap_gtc
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating eap-gtc
Fri Apr 9 05:12:31 2010 : Debug: gtc {
Fri Apr 9 05:12:31 2010 : Debug: challenge = "Password: "
Fri Apr 9 05:12:31 2010 : Debug: auth_type = "PAP"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to sub-module rlm_eap_tls
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating eap-tls
Fri Apr 9 05:12:31 2010 : Debug: tls {
Fri Apr 9 05:12:31 2010 : Debug: rsa_key_exchange = no
Fri Apr 9 05:12:31 2010 : Debug: dh_key_exchange = yes
Fri Apr 9 05:12:31 2010 : Debug: rsa_key_length = 512
Fri Apr 9 05:12:31 2010 : Debug: dh_key_length = 512
Fri Apr 9 05:12:31 2010 : Debug: verify_depth = 0
Fri Apr 9 05:12:31 2010 : Debug: pem_file_type = yes
Fri Apr 9 05:12:31 2010 : Debug: private_key_file = "/root/SW/Xsupplicant/keyname.pem"
Fri Apr 9 05:12:31 2010 : Debug: certificate_file = "/root/SW/Xsupplicant/certnew.pem"
Fri Apr 9 05:12:31 2010 : Debug: CA_file = "/root/SW/Xsupplicant/root_cert.pem"
Fri Apr 9 05:12:31 2010 : Debug: private_key_password = "password"
Fri Apr 9 05:12:31 2010 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh"
Fri Apr 9 05:12:31 2010 : Debug: random_file = "/dev/urandom"
Fri Apr 9 05:12:31 2010 : Debug: fragment_size = 1024
Fri Apr 9 05:12:31 2010 : Debug: include_length = yes
Fri Apr 9 05:12:31 2010 : Debug: check_crl = no
Fri Apr 9 05:12:31 2010 : Debug: cipher_list = "DEFAULT"
Fri Apr 9 05:12:31 2010 : Debug: make_cert_command = "/usr/local/etc/raddb/certs/bootstrap"
Fri Apr 9 05:12:31 2010 : Debug: cache {
Fri Apr 9 05:12:31 2010 : Debug: enable = no
Fri Apr 9 05:12:31 2010 : Debug: lifetime = 24
Fri Apr 9 05:12:31 2010 : Debug: max_entries = 255
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to sub-module rlm_eap_ttls
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating eap-ttls
Fri Apr 9 05:12:31 2010 : Debug: ttls {
Fri Apr 9 05:12:31 2010 : Debug: default_eap_type = "mschapv2"
Fri Apr 9 05:12:31 2010 : Debug: copy_request_to_tunnel = no
Fri Apr 9 05:12:31 2010 : Debug: use_tunneled_reply = no
Fri Apr 9 05:12:31 2010 : Debug: virtual_server = "inner-tunnel"
Fri Apr 9 05:12:31 2010 : Debug: include_length = yes
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to sub-module rlm_eap_peap
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating eap-peap
Fri Apr 9 05:12:31 2010 : Debug: peap {
Fri Apr 9 05:12:31 2010 : Debug: default_eap_type = "mschapv2"
Fri Apr 9 05:12:31 2010 : Debug: copy_request_to_tunnel = no
Fri Apr 9 05:12:31 2010 : Debug: use_tunneled_reply = no
Fri Apr 9 05:12:31 2010 : Debug: proxy_tunneled_request_as_eap = yes
Fri Apr 9 05:12:31 2010 : Debug: virtual_server = "inner-tunnel"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to sub-module rlm_eap_mschapv2
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating eap-mschapv2
Fri Apr 9 05:12:31 2010 : Debug: mschapv2 {
Fri Apr 9 05:12:31 2010 : Debug: with_ntdomain_hack = no
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking authorize {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_realm, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_realm
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating suffix
Fri Apr 9 05:12:31 2010 : Debug: realm suffix {
Fri Apr 9 05:12:31 2010 : Debug: format = "suffix"
Fri Apr 9 05:12:31 2010 : Debug: delimiter = "@"
Fri Apr 9 05:12:31 2010 : Debug: ignore_default = no
Fri Apr 9 05:12:31 2010 : Debug: ignore_null = no
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_files, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_files
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating files
Fri Apr 9 05:12:31 2010 : Debug: files {
Fri Apr 9 05:12:31 2010 : Debug: usersfile = "/usr/local/etc/raddb/users"
Fri Apr 9 05:12:31 2010 : Debug: acctusersfile = "/usr/local/etc/raddb/acct_users"
Fri Apr 9 05:12:31 2010 : Debug: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
Fri Apr 9 05:12:31 2010 : Debug: compat = "no"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking session {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_radutmp, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_radutmp
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating radutmp
Fri Apr 9 05:12:31 2010 : Debug: radutmp {
Fri Apr 9 05:12:31 2010 : Debug: filename = "/usr/local/var/log/radius/radutmp"
Fri Apr 9 05:12:31 2010 : Debug: username = "%{User-Name}"
Fri Apr 9 05:12:31 2010 : Debug: case_sensitive = yes
Fri Apr 9 05:12:31 2010 : Debug: check_with_nas = yes
Fri Apr 9 05:12:31 2010 : Debug: perm = 384
Fri Apr 9 05:12:31 2010 : Debug: callerid = yes
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking post-proxy {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking post-auth {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_attr_filter, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_attr_filter
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating attr_filter.access_reject
Fri Apr 9 05:12:31 2010 : Debug: attr_filter attr_filter.access_reject {
Fri Apr 9 05:12:31 2010 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.access_reject"
Fri Apr 9 05:12:31 2010 : Debug: key = "%{User-Name}"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: } # modules
Fri Apr 9 05:12:31 2010 : Debug: } # server
Fri Apr 9 05:12:31 2010 : Debug: server {
Fri Apr 9 05:12:31 2010 : Debug: modules {
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking authenticate {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking authorize {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_preprocess, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_preprocess
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating preprocess
Fri Apr 9 05:12:31 2010 : Debug: preprocess {
Fri Apr 9 05:12:31 2010 : Debug: huntgroups = "/usr/local/etc/raddb/huntgroups"
Fri Apr 9 05:12:31 2010 : Debug: hints = "/usr/local/etc/raddb/hints"
Fri Apr 9 05:12:31 2010 : Debug: with_ascend_hack = no
Fri Apr 9 05:12:31 2010 : Debug: ascend_channels_per_line = 23
Fri Apr 9 05:12:31 2010 : Debug: with_ntdomain_hack = no
Fri Apr 9 05:12:31 2010 : Debug: with_specialix_jetstream_hack = no
Fri Apr 9 05:12:31 2010 : Debug: with_cisco_vsa_hack = no
Fri Apr 9 05:12:31 2010 : Debug: with_alvarion_vsa_hack = no
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking preacct {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_acct_unique, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_acct_unique
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating acct_unique
Fri Apr 9 05:12:31 2010 : Debug: acct_unique {
Fri Apr 9 05:12:31 2010 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking accounting {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: (Loaded rlm_detail, checking if it's valid)
Fri Apr 9 05:12:31 2010 : Debug: Module: Linked to module rlm_detail
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating detail
Fri Apr 9 05:12:31 2010 : Debug: detail {
Fri Apr 9 05:12:31 2010 : Debug: detailfile = "/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Fri Apr 9 05:12:31 2010 : Debug: header = "%t"
Fri Apr 9 05:12:31 2010 : Debug: detailperm = 384
Fri Apr 9 05:12:31 2010 : Debug: dirperm = 493
Fri Apr 9 05:12:31 2010 : Debug: locking = no
Fri Apr 9 05:12:31 2010 : Debug: log_packet_header = no
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Instantiating attr_filter.accounting_response
Fri Apr 9 05:12:31 2010 : Debug: attr_filter attr_filter.accounting_response {
Fri Apr 9 05:12:31 2010 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"
Fri Apr 9 05:12:31 2010 : Debug: key = "%{User-Name}"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking session {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking post-proxy {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: Module: Checking post-auth {...} for more modules to load
Fri Apr 9 05:12:31 2010 : Debug: } # modules
Fri Apr 9 05:12:31 2010 : Debug: } # server
Fri Apr 9 05:12:31 2010 : Debug: radiusd: #### Opening IP addresses and Ports ####
Fri Apr 9 05:12:31 2010 : Debug: listen {
Fri Apr 9 05:12:31 2010 : Debug: type = "auth"
Fri Apr 9 05:12:31 2010 : Debug: ipaddr = *
Fri Apr 9 05:12:31 2010 : Debug: port = 0
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: listen {
Fri Apr 9 05:12:31 2010 : Debug: type = "acct"
Fri Apr 9 05:12:31 2010 : Debug: ipaddr = *
Fri Apr 9 05:12:31 2010 : Debug: port = 0
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: listen {
Fri Apr 9 05:12:31 2010 : Debug: type = "control"
Fri Apr 9 05:12:31 2010 : Debug: listen {
Fri Apr 9 05:12:31 2010 : Debug: socket = "/usr/local/var/run/radiusd/radiusd.sock"
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: }
Fri Apr 9 05:12:31 2010 : Debug: Listening on authentication address * port 1812
Fri Apr 9 05:12:31 2010 : Debug: Listening on accounting address * port 1813
Fri Apr 9 05:12:31 2010 : Debug: Listening on command file /usr/local/var/run/radiusd/radiusd.sock
Fri Apr 9 05:12:31 2010 : Debug: Listening on proxy address * port 1814
Fri Apr 9 05:12:31 2010 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=0, length=81
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406913537
EAP-Message = 0x0202000d017465737475736572
Message-Authenticator = 0xf82eb7c92d2899fe68240f297804c282
Fri Apr 9 05:12:37 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:37 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:37 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:37 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:37 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:37 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:37 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:37 2010 : Info: [eap] EAP packet type response id 2 length 13
Fri Apr 9 05:12:37 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:37 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:37 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:37 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:37 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:37 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:37 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:37 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:37 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:37 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:37 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:37 2010 : Info: [eap] EAP Identity
Fri Apr 9 05:12:37 2010 : Info: [eap] processing type tls
Fri Apr 9 05:12:37 2010 : Info: [tls] Initiate
Fri Apr 9 05:12:37 2010 : Info: [tls] Start returned 1
Fri Apr 9 05:12:37 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.37.18.108 port 32774
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfed7c105fed4d8b64698914296c27f73
Fri Apr 9 05:12:37 2010 : Info: Finished request 0.
Fri Apr 9 05:12:37 2010 : Debug: Going to the next request
Fri Apr 9 05:12:37 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=1, length=92
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406913537
State = 0xfed7c105fed4d8b64698914296c27f73
EAP-Message = 0x020300060304
Message-Authenticator = 0xee94d16288c018545f9ff35481568248
Fri Apr 9 05:12:38 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:38 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:38 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:38 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:38 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:38 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:38 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:38 2010 : Info: [eap] EAP packet type response id 3 length 6
Fri Apr 9 05:12:38 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:38 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:38 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:38 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:38 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:38 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:38 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:38 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:38 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:38 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:38 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:38 2010 : Info: [eap] Request found, released from the list
Fri Apr 9 05:12:38 2010 : Info: [eap] EAP NAK
Fri Apr 9 05:12:38 2010 : Info: [eap] EAP-NAK asked for EAP-Type/md5
Fri Apr 9 05:12:38 2010 : Info: [eap] processing type md5
Fri Apr 9 05:12:38 2010 : Debug: rlm_eap_md5: Issuing Challenge
Fri Apr 9 05:12:38 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 1 to 10.37.18.108 port 32774
EAP-Message = 0x0104001604107c7195033951c3050c98f0e6d4a3dee6
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfed7c105ffd3c5b64698914296c27f73
Fri Apr 9 05:12:38 2010 : Info: Finished request 1.
Fri Apr 9 05:12:38 2010 : Debug: Going to the next request
Fri Apr 9 05:12:38 2010 : Debug: Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=2, length=116
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406913537
State = 0xfed7c105ffd3c5b64698914296c27f73
EAP-Message = 0x0204001e04102adeab76fb6cc27d3f67e4c5e6b2180e7465737475736572
Message-Authenticator = 0xe6a2a2ae18f6d892c8f9cb30820a43a2
Fri Apr 9 05:12:38 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:38 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:38 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:38 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:38 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:38 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:38 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:38 2010 : Info: [eap] EAP packet type response id 4 length 30
Fri Apr 9 05:12:38 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:38 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:38 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:38 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:38 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:38 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:38 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:38 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:38 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:38 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:38 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:38 2010 : Info: [eap] Request found, released from the list
Fri Apr 9 05:12:38 2010 : Info: [eap] EAP/md5
Fri Apr 9 05:12:38 2010 : Info: [eap] processing type md5
Fri Apr 9 05:12:38 2010 : Info: [eap] Freeing handler
Fri Apr 9 05:12:38 2010 : Info: ++[eap] returns ok
Fri Apr 9 05:12:38 2010 : Info: +- entering group post-auth {...}
Fri Apr 9 05:12:38 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 2 to 10.37.18.108 port 32774
EAP-Message = 0x03040004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "testuser"
Fri Apr 9 05:12:38 2010 : Info: Finished request 2.
Fri Apr 9 05:12:38 2010 : Debug: Going to the next request
Fri Apr 9 05:12:38 2010 : Debug: Waking up in 4.4 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=3, length=81
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406848000
EAP-Message = 0x0202000d017465737475736572
Message-Authenticator = 0xd6e2ecc872ece2b5224619802824b104
Fri Apr 9 05:12:39 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:39 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:39 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:39 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:39 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:39 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:39 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:39 2010 : Info: [eap] EAP packet type response id 2 length 13
Fri Apr 9 05:12:39 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:39 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:39 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:39 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:39 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:39 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:39 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:39 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:39 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:39 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:39 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:39 2010 : Info: [eap] EAP Identity
Fri Apr 9 05:12:39 2010 : Info: [eap] processing type tls
Fri Apr 9 05:12:39 2010 : Info: [tls] Initiate
Fri Apr 9 05:12:39 2010 : Info: [tls] Start returned 1
Fri Apr 9 05:12:39 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 3 to 10.37.18.108 port 32774
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6940fc336943e5749244849618765ae0
Fri Apr 9 05:12:39 2010 : Info: Finished request 3.
Fri Apr 9 05:12:39 2010 : Debug: Going to the next request
Fri Apr 9 05:12:39 2010 : Debug: Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=4, length=92
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406848000
State = 0x6940fc336943e5749244849618765ae0
EAP-Message = 0x020300060304
Message-Authenticator = 0x5b0f995330bef6938ced07dd3e4d3565
Fri Apr 9 05:12:40 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:40 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:40 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:40 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:40 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:40 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:40 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:40 2010 : Info: [eap] EAP packet type response id 3 length 6
Fri Apr 9 05:12:40 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:40 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:40 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:40 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:40 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:40 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:40 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:40 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:40 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:40 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:40 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:40 2010 : Info: [eap] Request found, released from the list
Fri Apr 9 05:12:40 2010 : Info: [eap] EAP NAK
Fri Apr 9 05:12:40 2010 : Info: [eap] EAP-NAK asked for EAP-Type/md5
Fri Apr 9 05:12:40 2010 : Info: [eap] processing type md5
Fri Apr 9 05:12:40 2010 : Debug: rlm_eap_md5: Issuing Challenge
Fri Apr 9 05:12:40 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 4 to 10.37.18.108 port 32774
EAP-Message = 0x01040016041066115a556c837ff8ce3092b7d21e41ab
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6940fc336844f8749244849618765ae0
Fri Apr 9 05:12:40 2010 : Info: Finished request 4.
Fri Apr 9 05:12:40 2010 : Debug: Going to the next request
Fri Apr 9 05:12:40 2010 : Debug: Waking up in 2.7 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=5, length=116
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406848000
State = 0x6940fc336844f8749244849618765ae0
EAP-Message = 0x0204001e04108fcc0815933f7ca514870db8cfd8675a7465737475736572
Message-Authenticator = 0xe2505cf1ecaa4db6be0b1e17f0782134
Fri Apr 9 05:12:40 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:40 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:40 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:40 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:40 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:40 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:40 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:40 2010 : Info: [eap] EAP packet type response id 4 length 30
Fri Apr 9 05:12:40 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:40 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:40 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:40 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:40 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:40 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:40 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:40 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:40 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:40 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:40 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:40 2010 : Info: [eap] Request found, released from the list
Fri Apr 9 05:12:40 2010 : Info: [eap] EAP/md5
Fri Apr 9 05:12:40 2010 : Info: [eap] processing type md5
Fri Apr 9 05:12:40 2010 : Info: [eap] Freeing handler
Fri Apr 9 05:12:40 2010 : Info: ++[eap] returns ok
Fri Apr 9 05:12:40 2010 : Info: +- entering group post-auth {...}
Fri Apr 9 05:12:40 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 5 to 10.37.18.108 port 32774
EAP-Message = 0x03040004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "testuser"
Fri Apr 9 05:12:40 2010 : Info: Finished request 5.
Fri Apr 9 05:12:40 2010 : Debug: Going to the next request
Fri Apr 9 05:12:40 2010 : Debug: Waking up in 2.4 seconds.
Fri Apr 9 05:12:42 2010 : Info: Cleaning up request 0 ID 0 with timestamp +6
Fri Apr 9 05:12:42 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr 9 05:12:43 2010 : Info: Cleaning up request 1 ID 1 with timestamp +7
Fri Apr 9 05:12:43 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr 9 05:12:43 2010 : Info: Cleaning up request 2 ID 2 with timestamp +7
Fri Apr 9 05:12:43 2010 : Debug: Waking up in 1.4 seconds.
Fri Apr 9 05:12:44 2010 : Info: Cleaning up request 3 ID 3 with timestamp +8
Fri Apr 9 05:12:44 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr 9 05:12:45 2010 : Info: Cleaning up request 4 ID 4 with timestamp +9
Fri Apr 9 05:12:45 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr 9 05:12:45 2010 : Info: Cleaning up request 5 ID 5 with timestamp +9
Fri Apr 9 05:12:45 2010 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=6, length=81
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406913537
EAP-Message = 0x0201000d017465737475736572
Message-Authenticator = 0xc7f0609eff6b7fd2dec8109a5348db92
Fri Apr 9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP packet type response id 1 length 13
Fri Apr 9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP Identity
Fri Apr 9 05:12:56 2010 : Info: [eap] processing type tls
Fri Apr 9 05:12:56 2010 : Info: [tls] Initiate
Fri Apr 9 05:12:56 2010 : Info: [tls] Start returned 1
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 6 to 10.37.18.108 port 32774
EAP-Message = 0x010200061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfda61154fda408aa4e5f772b926dcec0
Fri Apr 9 05:12:56 2010 : Info: Finished request 6.
Fri Apr 9 05:12:56 2010 : Debug: Going to the next request
Fri Apr 9 05:12:56 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=7, length=81
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406848000
EAP-Message = 0x0201000d017465737475736572
Message-Authenticator = 0x1ac2eed0281f511c36e8646f9ecd0eb3
Fri Apr 9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP packet type response id 1 length 13
Fri Apr 9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP Identity
Fri Apr 9 05:12:56 2010 : Info: [eap] processing type tls
Fri Apr 9 05:12:56 2010 : Info: [tls] Initiate
Fri Apr 9 05:12:56 2010 : Info: [tls] Start returned 1
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 7 to 10.37.18.108 port 32774
EAP-Message = 0x010200061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x9adb6d8e9ad9748f58d1c4737f9f229b
Fri Apr 9 05:12:56 2010 : Info: Finished request 7.
Fri Apr 9 05:12:56 2010 : Debug: Going to the next request
Fri Apr 9 05:12:56 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=8, length=92
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406913537
State = 0x9adb6d8e9ad9748f58d1c4737f9f229b
EAP-Message = 0x020200060304
Message-Authenticator = 0xa8beb5bd658bce6a9076f7e27eba308f
Fri Apr 9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP packet type response id 2 length 6
Fri Apr 9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:56 2010 : Info: [eap] Request found, released from the list
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP NAK
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP-NAK asked for EAP-Type/md5
Fri Apr 9 05:12:56 2010 : Info: [eap] processing type md5
Fri Apr 9 05:12:56 2010 : Debug: rlm_eap_md5: Issuing Challenge
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 8 to 10.37.18.108 port 32774
EAP-Message = 0x0103001604108f152f3420a03e075ce69c869cca4624
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x9adb6d8e9bd8698f58d1c4737f9f229b
Fri Apr 9 05:12:56 2010 : Info: Finished request 8.
Fri Apr 9 05:12:56 2010 : Debug: Going to the next request
Fri Apr 9 05:12:56 2010 : Debug: Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=9, length=92
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406848000
State = 0x9adb6d8e9ad9748f58d1c4737f9f229b
EAP-Message = 0x020200060304
Message-Authenticator = 0x7cd0fe2d39f50ba97736d0d7c90508a1
Fri Apr 9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP packet type response id 2 length 6
Fri Apr 9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:56 2010 : Error: rlm_eap: No EAP session matching the State variable.
Fri Apr 9 05:12:56 2010 : Info: [eap] Either EAP-request timed out OR EAP-response to an unknown EAP-request
Fri Apr 9 05:12:56 2010 : Info: [eap] Failed in handler
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns invalid
Fri Apr 9 05:12:56 2010 : Info: Failed to authenticate the user.
Fri Apr 9 05:12:56 2010 : Info: Using Post-Auth-Type Reject
Fri Apr 9 05:12:56 2010 : Info: +- entering group REJECT {...}
Fri Apr 9 05:12:56 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> testuser
Fri Apr 9 05:12:56 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11
Fri Apr 9 05:12:56 2010 : Info: ++[attr_filter.access_reject] returns updated
Fri Apr 9 05:12:56 2010 : Info: Delaying reject of request 9 for 1 seconds
Fri Apr 9 05:12:56 2010 : Debug: Going to the next request
Fri Apr 9 05:12:56 2010 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=10, length=116
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406913537
State = 0x9adb6d8e9bd8698f58d1c4737f9f229b
EAP-Message = 0x0203001e041067c814ba64a55fa3e62a6b6c3863c7717465737475736572
Message-Authenticator = 0xf2482c4ffa128045ef37b191ad60366f
Fri Apr 9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP packet type response id 3 length 30
Fri Apr 9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr 9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:12:56 2010 : Info: [eap] Request found, released from the list
Fri Apr 9 05:12:56 2010 : Info: [eap] EAP/md5
Fri Apr 9 05:12:56 2010 : Info: [eap] processing type md5
Fri Apr 9 05:12:56 2010 : Info: [eap] Freeing handler
Fri Apr 9 05:12:56 2010 : Info: ++[eap] returns ok
Fri Apr 9 05:12:56 2010 : Info: +- entering group post-auth {...}
Fri Apr 9 05:12:56 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 10 to 10.37.18.108 port 32774
EAP-Message = 0x03030004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "testuser"
Fri Apr 9 05:12:56 2010 : Info: Finished request 10.
Fri Apr 9 05:12:56 2010 : Debug: Going to the next request
Fri Apr 9 05:12:56 2010 : Debug: Waking up in 0.7 seconds.
Fri Apr 9 05:12:57 2010 : Info: Sending delayed reject for request 9
Sending Access-Reject of id 9 to 10.37.18.108 port 32774
Fri Apr 9 05:12:57 2010 : Debug: Waking up in 3.7 seconds.
Fri Apr 9 05:13:01 2010 : Info: Cleaning up request 6 ID 6 with timestamp +25
Fri Apr 9 05:13:01 2010 : Info: Cleaning up request 7 ID 7 with timestamp +25
Fri Apr 9 05:13:01 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr 9 05:13:01 2010 : Info: Cleaning up request 8 ID 8 with timestamp +25
Fri Apr 9 05:13:01 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr 9 05:13:01 2010 : Info: Cleaning up request 10 ID 10 with timestamp +25
Fri Apr 9 05:13:01 2010 : Debug: Waking up in 0.7 seconds.
Fri Apr 9 05:13:02 2010 : Info: Cleaning up request 9 ID 9 with timestamp +25
Fri Apr 9 05:13:02 2010 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=11, length=81
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406848000
EAP-Message = 0x0204000d017465737475736572
Message-Authenticator = 0xea32d9f24d334b6e71a403bb64e806af
Fri Apr 9 05:13:30 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:13:30 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:13:30 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:13:30 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:13:30 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:13:30 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:13:30 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:13:30 2010 : Info: [eap] EAP packet type response id 4 length 13
Fri Apr 9 05:13:30 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:13:30 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:13:30 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:13:30 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:13:30 2010 : Info: ++[files] returns ok
Fri Apr 9 05:13:30 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:13:30 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:13:30 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:13:30 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:13:30 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:13:30 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:13:30 2010 : Info: [eap] EAP Identity
Fri Apr 9 05:13:30 2010 : Info: [eap] processing type tls
Fri Apr 9 05:13:30 2010 : Info: [tls] Initiate
Fri Apr 9 05:13:30 2010 : Info: [tls] Start returned 1
Fri Apr 9 05:13:30 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 11 to 10.37.18.108 port 32774
EAP-Message = 0x010500061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6c90013e6c9518adc200fb210d4c749a
Fri Apr 9 05:13:30 2010 : Info: Finished request 11.
Fri Apr 9 05:13:30 2010 : Debug: Going to the next request
Fri Apr 9 05:13:30 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=12, length=92
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406848000
State = 0x6c90013e6c9518adc200fb210d4c749a
EAP-Message = 0x020500060304
Message-Authenticator = 0x609a7f9e553920fe0987403c2933723a
Fri Apr 9 05:13:30 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:13:30 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:13:30 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:13:30 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:13:30 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:13:30 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:13:30 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:13:30 2010 : Info: [eap] EAP packet type response id 5 length 6
Fri Apr 9 05:13:30 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:13:30 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:13:30 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:13:30 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:13:30 2010 : Info: ++[files] returns ok
Fri Apr 9 05:13:30 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:13:30 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:13:30 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:13:30 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:13:30 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:13:30 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:13:30 2010 : Info: [eap] Request found, released from the list
Fri Apr 9 05:13:30 2010 : Info: [eap] EAP NAK
Fri Apr 9 05:13:30 2010 : Info: [eap] EAP-NAK asked for EAP-Type/md5
Fri Apr 9 05:13:30 2010 : Info: [eap] processing type md5
Fri Apr 9 05:13:30 2010 : Debug: rlm_eap_md5: Issuing Challenge
Fri Apr 9 05:13:30 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 12 to 10.37.18.108 port 32774
EAP-Message = 0x0106001604106101f5a6ce9f14a96f0889a50307a6be
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6c90013e6d9605adc200fb210d4c749a
Fri Apr 9 05:13:30 2010 : Info: Finished request 12.
Fri Apr 9 05:13:30 2010 : Debug: Going to the next request
Fri Apr 9 05:13:30 2010 : Debug: Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=13, length=116
User-Name = "testuser"
Framed-MTU = 1000
NAS-IP-Address = 10.37.18.108
NAS-Port = 406848000
State = 0x6c90013e6d9605adc200fb210d4c749a
EAP-Message = 0x0206001e04105760a2073c5b4976e7bcc1dd2b83dee27465737475736572
Message-Authenticator = 0x45df310f4d4aa4c0bfbcae5756e74ad9
Fri Apr 9 05:13:30 2010 : Info: +- entering group authorize {...}
Fri Apr 9 05:13:30 2010 : Info: ++[preprocess] returns ok
Fri Apr 9 05:13:30 2010 : Info: ++[chap] returns noop
Fri Apr 9 05:13:30 2010 : Info: ++[mschap] returns noop
Fri Apr 9 05:13:30 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr 9 05:13:30 2010 : Info: [suffix] No such realm "NULL"
Fri Apr 9 05:13:30 2010 : Info: ++[suffix] returns noop
Fri Apr 9 05:13:30 2010 : Info: [eap] EAP packet type response id 6 length 30
Fri Apr 9 05:13:30 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr 9 05:13:30 2010 : Info: ++[eap] returns updated
Fri Apr 9 05:13:30 2010 : Info: ++[unix] returns notfound
Fri Apr 9 05:13:30 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr 9 05:13:30 2010 : Info: ++[files] returns ok
Fri Apr 9 05:13:30 2010 : Info: ++[expiration] returns noop
Fri Apr 9 05:13:30 2010 : Info: ++[logintime] returns noop
Fri Apr 9 05:13:30 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr 9 05:13:30 2010 : Info: ++[pap] returns noop
Fri Apr 9 05:13:30 2010 : Info: Found Auth-Type = EAP
Fri Apr 9 05:13:30 2010 : Info: +- entering group authenticate {...}
Fri Apr 9 05:13:30 2010 : Info: [eap] Request found, released from the list
Fri Apr 9 05:13:30 2010 : Info: [eap] EAP/md5
Fri Apr 9 05:13:30 2010 : Info: [eap] processing type md5
Fri Apr 9 05:13:30 2010 : Info: [eap] Freeing handler
Fri Apr 9 05:13:30 2010 : Info: ++[eap] returns ok
Fri Apr 9 05:13:30 2010 : Info: +- entering group post-auth {...}
Fri Apr 9 05:13:30 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 13 to 10.37.18.108 port 32774
EAP-Message = 0x03060004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "testuser"
Fri Apr 9 05:13:30 2010 : Info: Finished request 13.
Fri Apr 9 05:13:30 2010 : Debug: Going to the next request
Fri Apr 9 05:13:30 2010 : Debug: Waking up in 4.4 seconds.
Fri Apr 9 05:13:35 2010 : Info: Cleaning up request 11 ID 11 with timestamp +59
Fri Apr 9 05:13:35 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr 9 05:13:35 2010 : Info: Cleaning up request 12 ID 12 with timestamp +59
Fri Apr 9 05:13:35 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr 9 05:13:35 2010 : Info: Cleaning up request 13 ID 13 with timestamp +59
Fri Apr 9 05:13:35 2010 : Debug: Ready to process requests.
More information about the Freeradius-Users
mailing list