Always Login incorrect: Could not extract EAP-Message from RADIUS message

17 Dec 2011

      Hi,

Sorry I resend the message because of original message was bounced
because it was too big.

I have a really weird problem. We have a lot of NAS'es and no one of
them had this problem, except only one! It gets always login
incorrect. If I run
eapol_test it complains saying. I've tried replacing the nas a few
times and makes no difference. And it doesnt' matter what user tries
to connect.

Please take a look to user "interup" with outer  identity "SOYKADORNA"

Am I doing something wrong?

Thanks in advance

Below the debug messsages:

FreeRADIUS Version 2.1.1, for host x86_64-unknown-linux-gnu, built on
Oct 21 2008 at 15:14:37
Copyright (C) 1999-2008 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License v2.
Starting - reading configuration files ...
including configuration file /usr/local/etc/raddb/radiusd.conf
including configuration file /usr/local/etc/raddb/proxy.conf
including configuration file /usr/local/etc/raddb/clients.conf
including files in directory /usr/local/etc/raddb/modules/
including configuration file /usr/local/etc/raddb/modules/chap
including configuration file /usr/local/etc/raddb/modules/mschap
including configuration file /usr/local/etc/raddb/modules/exec
including configuration file /usr/local/etc/raddb/modules/realm
including configuration file /usr/local/etc/raddb/modules/checkval
including configuration file /usr/local/etc/raddb/modules/passwd
including configuration file /usr/local/etc/raddb/modules/attr_filter
including configuration file /usr/local/etc/raddb/modules/files.backup
including configuration file /usr/local/etc/raddb/modules/linelog
including configuration file /usr/local/etc/raddb/modules/wimax
including configuration file /usr/local/etc/raddb/modules/pam
including configuration file /usr/local/etc/raddb/modules/inner-eap
including configuration file /usr/local/etc/raddb/modules/echo
including configuration file /usr/local/etc/raddb/modules/acct_unique
including configuration file /usr/local/etc/raddb/modules/etc_group
including configuration file /usr/local/etc/raddb/modules/pap
including configuration file /usr/local/etc/raddb/modules/expr
including configuration file /usr/local/etc/raddb/modules/smbpasswd
including configuration file /usr/local/etc/raddb/modules/attr_rewrite
including configuration file /usr/local/etc/raddb/modules/radutmp
including configuration file /usr/local/etc/raddb/modules/mac2ip
including configuration file /usr/local/etc/raddb/modules/logintime
including configuration file /usr/local/etc/raddb/modules/sql_log
including configuration file /usr/local/etc/raddb/modules/preprocess
including configuration file /usr/local/etc/raddb/modules/policy
including configuration file /usr/local/etc/raddb/modules/digest
including configuration file /usr/local/etc/raddb/modules/mac2vlan
including configuration file /usr/local/etc/raddb/modules/files
including configuration file /usr/local/etc/raddb/modules/always
including configuration file /usr/local/etc/raddb/modules/detail
including configuration file /usr/local/etc/raddb/modules/krb5
including configuration file /usr/local/etc/raddb/modules/sradutmp
including configuration file /usr/local/etc/raddb/modules/counter
including configuration file /usr/local/etc/raddb/modules/detail.example.com
including configuration file /usr/local/etc/raddb/modules/ippool
including configuration file /usr/local/etc/raddb/modules/expiration
including configuration file /usr/local/etc/raddb/modules/detail.log
including configuration file /usr/local/etc/raddb/modules/ldap
including configuration file /usr/local/etc/raddb/modules/unix
including configuration file /usr/local/etc/raddb/eap.conf
including configuration file /usr/local/etc/raddb/sql.conf
including configuration file /usr/local/etc/raddb/sql/mysql/dialup.conf
including configuration file /usr/local/etc/raddb/sql/mysql/counter.conf
including configuration file /usr/local/etc/raddb/policy.conf
including files in directory /usr/local/etc/raddb/sites-enabled/
including configuration file /usr/local/etc/raddb/sites-enabled/status
including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel
including configuration file /usr/local/etc/raddb/sites-enabled/default.backup
including configuration file /usr/local/etc/raddb/sites-enabled/default
including configuration file
/usr/local/etc/raddb/sites-enabled/inner-tunnel-peap
group = radiusd
user = radiusd
including dictionary file /usr/local/etc/raddb/dictionary
main {
       prefix = "/usr/local"
       localstatedir = "/usr/local/var"
       logdir = "/usr/local/var/log/radius"
       libdir = "/usr/local/lib"
       radacctdir = "/usr/local/var/log/radius/radacct"
       hostname_lookups = no
       max_request_time = 30
       cleanup_delay = 5
       max_requests = 1024
       allow_core_dumps = no
       pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
       checkrad = "/usr/local/sbin/checkrad"
       debug_level = 0
       proxy_requests = no
 log {
       stripped_names = yes
       auth = yes
       auth_badpass = no
       auth_goodpass = no
 }
 security {
       max_attributes = 200
       reject_delay = 1
       status_server = yes
 }
}
 client localhost {
       ipaddr = 127.0.0.1
       require_message_authenticator = no
       secret = "testing123"
       nastype = "other"
 }
 client spectrum {
       require_message_authenticator = no
       secret = "testing123"
       shortname = "spectrum.sarlanga.edu"
 }
 client 10.128.255.100 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-PB"
 }
 client 10.129.0.100 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-PB"
 }
 client 10.128.255.10 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-SS"
 }
 client 10.129.0.10 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-SS"
 }
 client 10.128.255.11 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-1"
 }
 client 10.129.0.11 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-1"
 }
 client 10.129.0.199 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "Transitional"
 }
 client 10.129.254.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "Transitional"
 }
 client 10.129.0.12 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-2"
 }
 client 10.129.0.111 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-2-bis"
 }
 client 10.128.255.13 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-3"
 }
 client 10.129.0.13 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-3"
 }
 client 10.128.255.14 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-4"
 }
 client 10.129.0.14 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-4"
 }
 client 10.128.255.15 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-5"
 }
 client 10.129.0.15 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-3-winnie"
       shortname = "AP-PI-5"
 }
 client 10.128.255.60 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-Sociales-0"
 }
 client 10.129.0.60 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-Sociales-0"
 }
 client 10.128.255.61 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-Sociales-I"
 }
 client 10.129.0.61 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-Sociales-I"
 }
 client 10.129.158.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-SS"
 }
 client 10.129.80.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-PB"
 }
 client 10.128.255.81 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-I"
 }
 client 10.129.81.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-I"
 }
 client 10.128.255.82 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-II"
 }
 client 10.129.82.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-II"
 }
 client 10.128.250.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-Bridge"
 }
 client 10.128.255.172 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-I_bis_test"
 }
 client 10.128.255.83 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-III"
 }
 client 10.129.0.83 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-III"
 }
 client 10.129.83.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-III"
 }
 client 10.128.255.84 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-IV"
 }
 client 10.129.84.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-IV"
 }
 client 10.128.255.181 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-I_bis"
 }
 client 10.129.181.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-I_bis"
 }
 client 10.129.162.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-I_bis_2"
 }
 client 10.128.255.86 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-VI"
 }
 client 10.129.86.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-VI"
 }
 client 10.128.255.87 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-VII"
 }
 client 10.129.0.87 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-VII"
 }
 client 10.129.87.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-VII"
 }
 client 10.129.187.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-VII-Derecho"
 }
 client 10.129.99.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-Pivot"
 }
 client 10.128.255.52 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PV-PB"
 }
 client 10.128.255.85 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-V"
 }
 client 10.129.0.85 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-V"
 }
 client 10.129.85.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-V"
 }
 client 10.129.0.189 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-IX-HD"
 }
 client 10.129.189.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-IX-HD"
 }
 client 10.129.88.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-PVIII-VIII"
 }
 client 10.129.0.89 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "oficina-test"
 }
 client 10.129.89.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "oficina-test"
 }
 client 10.128.255.160 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-Sociales-Auditorio"
 }
 client 10.128.255.190 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-NONAT"
 }
 client 10.129.90.1 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "sarlanga-X"
 }
 client 192.168.2.53 {
       require_message_authenticator = no
       secret = "akantilad0-Green-22"
       shortname = "sarlanga3"
 }
 client 192.168.45 {
       require_message_authenticator = no
       secret = "sarlangalad0-black-54"
       shortname = "sarlanga4"
 }
 client 192.168.3.201 {
       require_message_authenticator = no
       secret = "sarlangalad0-blue-246692"
       shortname = "sarlanga7"
 }
 client 192.168.4 {
       require_message_authenticator = no
       secret = "PEPE"
       shortname = "AP-sarlanga7"
 }
 client 192.168.142.240 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-Cabre-1"
 }
 client 192.168.142.241 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-Cabre-2"
 }
 client 192.168.142.242 {
       require_message_authenticator = no
       secret = "sarlangalad0-Red-398952"
       shortname = "AP-Cabre-3"
 }
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
       retry_delay = 5
       retry_count = 3
       default_fallback = no
       dead_time = 120
       wake_all_if_all_dead = no
 }
 home_server localhost {
       ipaddr = 127.0.0.1
       port = 1812
       type = "auth"
       secret = "testing123"
       response_window = 20
       max_outstanding = 65536
       zombie_period = 40
       status_check = "status-server"
       ping_interval = 30
       check_interval = 30
       num_answers_to_alive = 3
       num_pings_to_alive = 3
       revive_interval = 120
       status_check_timeout = 4
 }
 home_server_pool my_auth_failover {
       type = fail-over
       home_server = localhost
 }
 realm example.com {
       auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating exec
 exec {
       wait = no
       input_pairs = "request"
       shell_escape = yes
 }
 Module: Linked to module rlm_expr
 Module: Instantiating expr
 Module: Linked to module rlm_expiration
 Module: Instantiating expiration
 expiration {
       reply-message = "Password Has Expired  "
 }
 Module: Linked to module rlm_logintime
 Module: Instantiating logintime
 logintime {
       reply-message = "You are calling outside your allowed timespan  "
       minimum-timeout = 60
 }
 }
radiusd: #### Loading Virtual Servers ####
server status {
 modules {
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_always
 Module: Instantiating ok
 always ok {
       rcode = "ok"
       simulcount = 0
       mpp = no
 }
 }
}
server inner-tunnel {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating pap
 pap {
       encryption_scheme = "auto"
       auto_header = yes
 }
 Module: Linked to module rlm_chap
 Module: Instantiating chap
 Module: Linked to module rlm_mschap
 Module: Instantiating mschap
 mschap {
       use_mppe = yes
       require_encryption = no
       require_strong = no
       with_ntdomain_hack = yes
 }
 Module: Linked to module rlm_unix
 Module: Instantiating unix
 unix {
       radwtmp = "/usr/local/var/log/radius/radwtmp"
 }
 Module: Linked to module rlm_ldap
 Module: Instantiating ldap
 ldap {
       server = "ldap.sarlanga.edu"
       port = 636
       password = "sarlanga"
       identity = "cn=freeradius,ou=applications,dc=sarlanga,dc=edu"
       net_timeout = 10
       timeout = 120
       timelimit = 30
       tls_mode = no
       start_tls = no
       tls_require_cert = "allow"
  tls {
       start_tls = no
       cacertfile = "/etc/raddb/cacert.pem"
       randfile = "/dev/urandom"
       require_cert = "demand"
  }
       basedn = "ou=people,dc=sarlanga,dc=edu"
       filter = "(uid=%u)"
       base_filter = "(objectclass=radiusprofile)"
       auto_header = no
       access_attr = "radiusAllowed"
       access_attr_used_for_allow = yes
       groupname_attribute = "cn"
       groupmembership_filter =
"(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))"
       dictionary_mapping = "/usr/local/etc/raddb/ldap.attrmap"
       ldap_debug = 40
       ldap_connections_number = 15
       compare_check_items = no
       do_xlat = yes
       set_auth_type = yes
 }
rlm_ldap: Registering ldap_groupcmp for Ldap-Group
rlm_ldap: Registering ldap_xlat with xlat_name ldap
rlm_ldap: reading ldap<->radius mappings from file
/usr/local/etc/raddb/ldap.attrmap
rlm_ldap: LDAP radiusPassword mapped to RADIUS Cleartext-Password
conns: 0xba35710
 Module: Linked to module rlm_eap
 Module: Instantiating eap
 eap {
       default_eap_type = "ttls"
       timer_expire = 600
       ignore_unknown_eap_types = no
       cisco_accounting_username_bug = no
       max_sessions = 2048
 }
 Module: Linked to sub-module rlm_eap_md5
 Module: Instantiating eap-md5
 Module: Linked to sub-module rlm_eap_leap
 Module: Instantiating eap-leap
 Module: Linked to sub-module rlm_eap_gtc
 Module: Instantiating eap-gtc
  gtc {
       challenge = "Password: "
       auth_type = "PAP"
  }
 Module: Linked to sub-module rlm_eap_tls
 Module: Instantiating eap-tls
  tls {
       rsa_key_exchange = no
       dh_key_exchange = yes
       rsa_key_length = 512
       dh_key_length = 512
       verify_depth = 0
       pem_file_type = yes
       private_key_file = "/etc/pki/tls/certs/ips-spectrum-key.pem"
       certificate_file = "/etc/pki/tls/certs/spectrum.sarlanga.edu.cer"
       CA_file = "/etc/pki/tls/certs/IPS-IPSCABUNDLE.crt"
       dh_file = "/usr/local/etc/raddb/certs/dh"
       random_file = "/usr/local/etc/raddb/certs/random"
       fragment_size = 1024
       include_length = yes
       check_crl = no
       cipher_list = "DEFAULT"
   cache {
       enable = yes
       lifetime = 6
       max_entries = 255
   }
  }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
  ttls {
       default_eap_type = "md5"
       copy_request_to_tunnel = yes
       use_tunneled_reply = yes
       virtual_server = "inner-tunnel"
  }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
  peap {
       default_eap_type = "mschapv2"
       copy_request_to_tunnel = yes
       use_tunneled_reply = yes
       proxy_tunneled_request_as_eap = yes
       virtual_server = "inner-tunnel-peap"
  }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
  mschapv2 {
       with_ntdomain_hack = no
  }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_realm
 Module: Instantiating suffix
 realm suffix {
       format = "suffix"
       delimiter = "@"
       ignore_default = no
       ignore_null = no
 }
 Module: Linked to module rlm_files
 Module: Instantiating files
 files {
       usersfile = "/usr/local/etc/raddb/users"
       acctusersfile = "/usr/local/etc/raddb/acct_users"
       preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
       compat = "no"
 }
 Module: Checking session {...} for more modules to load
 Module: Linked to module rlm_radutmp
 Module: Instantiating radutmp
 radutmp {
       filename = "/usr/local/var/log/radius/radutmp"
       username = "%{User-Name}"
       case_sensitive = yes
       check_with_nas = yes
       perm = 384
       callerid = yes
 }
 Module: Checking post-proxy {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating post_proxy_log
 detail post_proxy_log {
       detailfile =
"/usr/local/var/log/radius/radacct/postproxy/%{Client-IP-Address}/post-proxy-detail-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d"
       header = "%t"
       detailperm = 384
       dirperm = 493
       locking = no
       log_packet_header = no
 }
 Module: Checking post-auth {...} for more modules to load
 Module: Instantiating reply_log
 detail reply_log {
       detailfile =
"/usr/local/var/log/radius/radacct/replies/%{Client-IP-Address}/reply-detail-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d"
       header = "%t"
       detailperm = 384
       dirperm = 493
       locking = no
       log_packet_header = no
 }
 Module: Linked to module rlm_attr_filter
 Module: Instantiating attr_filter.access_reject
 attr_filter attr_filter.access_reject {
       attrsfile = "/usr/local/etc/raddb/attrs.access_reject"
       key = "%{User-Name}"
 }
 }
}
server inner-tunnel-peap {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Checking authorize {...} for more modules to load
 Module: Checking session {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 }
}
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating preprocess
 preprocess {
       huntgroups = "/usr/local/etc/raddb/huntgroups"
       hints = "/usr/local/etc/raddb/hints"
       with_ascend_hack = no
       ascend_channels_per_line = 23
       with_ntdomain_hack = no
       with_specialix_jetstream_hack = no
       with_cisco_vsa_hack = no
       with_alvarion_vsa_hack = no
 }
 Module: Instantiating auth_log
 detail auth_log {
       detailfile =
"/usr/local/var/log/radius/radacct/requests/%{Client-IP-Address}/auth-detail-%{NAS-Identifier}-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d"
       header = "%t"
       detailperm = 384
       dirperm = 493
       locking = no
       log_packet_header = no
 }
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating acct_unique
 acct_unique {
       key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
 }
 Module: Checking accounting {...} for more modules to load
 Module: Instantiating detail
 detail {
       detailfile =
"/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
       header = "%t"
       detailperm = 384
       dirperm = 493
       locking = no
       log_packet_header = no
 }
 Module: Instantiating attr_filter.accounting_response
 attr_filter attr_filter.accounting_response {
       attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"
       key = "%{User-Name}"
 }
 Module: Checking session {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 }
radiusd: #### Opening IP addresses and Ports ####
listen {
       type = "auth"
       ipaddr = 192.168.1.5
       port = 0
}
listen {
       type = "acct"
       ipaddr = 192.168.1.5
       port = 0
}
listen {
       type = "status"
       ipaddr = 127.0.0.1
       port = 18120
 client admin {
       ipaddr = 127.0.0.1
       require_message_authenticator = no
       secret = "YellowSubmarine"
 }
}
Listening on authentication address 192.168.1.5 port 1812
Listening on accounting address 192.168.1.5 port 1813
Listening on status address 127.0.0.1 port 18120 as server status
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.4 port 39611, id=0, length=128
       User-Name = "SOYKADORNA"
       NAS-IP-Address = 127.0.0.1
       Calling-Station-Id = "02-00-00-00-00-01"
       Framed-MTU = 1400
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 11Mbps 802.11b"
       EAP-Message = 0x0200000f01534f594b41444f524e41
       Message-Authenticator = 0x7d52a44c132c7bc77146e1c0f207d3a5
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]      expand: %{Virtual-Server} ->
[auth_log]      expand:
/usr/local/var/log/radius/radacct/requests/%{Client-IP-Address}/auth-detail-%{NAS-Identifier}-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d
-> /usr/local/var/log/radius/radacct/requests/192.168.4/auth-detail--DEFAULT-20111216
[auth_log] /usr/local/var/log/radius/radacct/requests/%{Client-IP-Address}/auth-detail-%{NAS-Identifier}-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d
expands to /usr/local/var/log/radius/radacct/requests/192.168.4/auth-detail--DEFAULT-20111216
[auth_log]      expand: %t -> Fri Dec 16 09:49:52 2011
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "SOYKADORNA", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 0 length 15
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 0 to 192.168.4 port 39611
       EAP-Message = 0x010100061520
       Message-Authenticator = 0x00000000000000000000000000000000
       State = 0x869e7309869f6616768684a64fbb490b
Finished request 8.
Going to the next request
Waking up in 3.5 seconds.
rad_recv: Access-Request packet from host 192.168.4 port 39611, id=1, length=137
       User-Name = "SOYKADORNA"
       NAS-IP-Address = 127.0.0.1
       Calling-Station-Id = "02-00-00-00-00-01"
       Framed-MTU = 1400
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 11Mbps 802.11b"
       EAP-Message = 0x020100060319
       State = 0x869e7309869f6616768684a64fbb490b
       Message-Authenticator = 0x5d842b0560785988f065cf3bf41a8be3
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]      expand: %{Virtual-Server} ->
[auth_log]      expand:
/usr/local/var/log/radius/radacct/requests/%{Client-IP-Address}/auth-detail-%{NAS-Identifier}-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d
-> /usr/local/var/log/radius/radacct/requests/192.168.4/auth-detail--DEFAULT-20111216
[auth_log] /usr/local/var/log/radius/radacct/requests/%{Client-IP-Address}/auth-detail-%{NAS-Identifier}-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d
expands to /usr/local/var/log/radius/radacct/requests/192.168.4/auth-detail--DEFAULT-20111216
[auth_log]      expand: %t -> Fri Dec 16 09:49:52 2011
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "SOYKADORNA", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/peap
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 1 to 192.168.4 port 39611
       EAP-Message = 0x010200061920
       Message-Authenticator = 0x00000000000000000000000000000000
       State = 0x869e7309879c6a16768684a64fbb490b
Finished request 9.
Going to the next request
Waking up in 3.5 seconds.
rad_recv: Access-Request packet from host 192.168.4 port 39611, id=2, length=253
       User-Name = "SOYKADORNA"
       NAS-IP-Address = 127.0.0.1
       Calling-Station-Id = "02-00-00-00-00-01"
       Framed-MTU = 1400
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 11Mbps 802.11b"
       EAP-Message =
0x0202007a198000000070160301006b0100006703014eeb3ec87be73aa918030263d5e73f349398bd48e8176a62ce944dcf0c6b95cf00003a00390038008800870035008400160013000a00330032009a009900450044002f00960041000500040015001200090014001100080006000300ff0100000400230000
       State = 0x869e7309879c6a16768684a64fbb490b
       Message-Authenticator = 0x0786010bb78d36cc0a93b73a3a9b7a0f
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]      expand: %{Virtual-Server} ->
[auth_log]      expand:
/usr/local/var/log/radius/radacct/requests/%{Client-IP-Address}/auth-detail-%{NAS-Identifier}-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d
-> /usr/local/var/log/radius/radacct/requests/192.168.4/auth-detail--DEFAULT-20111216
[auth_log] /usr/local/var/log/radius/radacct/requests/%{Client-IP-Address}/auth-detail-%{NAS-Identifier}-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d
expands to /usr/local/var/log/radius/radacct/requests/192.168.4/auth-detail--DEFAULT-20111216
[auth_log]      expand: %t -> Fri Dec 16 09:49:52 2011
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "SOYKADORNA", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 length 122
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
 TLS Length 112
[peap] Length Included
[peap] eaptls_verify returned 11
[peap]     (other): before/accept initialization
[peap]     TLS_accept: before/accept initialization
[peap] <<< TLS 1.0 Handshake [length 006b], ClientHello
[peap]     TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 004a], ServerHello
[peap]     TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 12d7], Certificate
[peap]     TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange
[peap]     TLS_accept: SSLv3 write key exchange A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap]     TLS_accept: SSLv3 write server done A
[peap]     TLS_accept: SSLv3 flush data
[peap]     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 2 to 192.168.4 port 39611
       EAP-Message =
0x0103040019c000001546160301004a0200004603014eeb3e70e9518efca476b6b6b1ec5e8f9c799fa944d0daf64f278fbe60fa8a3420de18117bfdbe7c3f59f33573e835815b6b0d41bc0a56955d16774908e8775ee800390016030112d70b0012d30012d00006ca308206c6308205aea003020102021410f491b39dcd293309a9046a42dcab1fe606ed72300d06092a864886f70d01010505003081b0310b3009060355040613024553310f300d060355040813064d4144524944310f300d060355040713064d414452494431243022060355040a131b6970732043657274696669636174696f6e20417574686f7269747931183016060355040b130f
       EAP-Message =
0x43657274696669636163696f6e657331193017060355040313106970734341204c6576656c20312043413124302206092a864886f70d010901161569707363616c6576656c314069707363612e636f6d301e170d3039313232323232353731355a170d3132303132373232353731355a30818d310b3009060355040613024152311530130603550407130c4275656e6f73204169726573311f301d060355040a1316556e6976657273696461642064652050616c65726d6f31273025060355040b131e446570617274616d656e746f20646520436f6d756e69636163696f6e6573311d301b06035504031314737065637472756d2e70616c65726d6f2e
       EAP-Message =
0x65647530820122300d06092a864886f70d01010105000382010f003082010a0282010100a8efabc6c785b1314fc7a643f75a6b1e1ae645b4ad47d23a5ce062cd3fa5a998112d48b88960da17628181430eb1e6dbcd806eb3b77ad9ca5728e86d333f9a910107d90c0e2dad1951587fb6ebe0b1f99665fad04e352e1d87dbf1a1292ae3cc8bb936511b10cc25facb79db7df50a443359a5c46213253cfbee9db5a262221e23d6961c6f2e4bff6c7702fe05eeff8c97c3c4558f84d3d61a1571017d5638863ec4f341613113aca1b385ae7598065503f28f78c83c632ebb0183d6d8ffd21edd8cd4db50c1550443f12706847a053769c1c5c7f94eff9fff
       EAP-Message =
0x8c3091d3892db2f35ab46dc208d1e03f37b82fb96d7fba474b42279ecb74157fdc521c038949dd0203010001a38202f7308202f330090603551d1304023000301106096086480186f8420101040403020640300b0603551d0f0404030205a030130603551d25040c300a06082b06010505070301301d0603551d0e04160414d57dbba6130341755d2138e3ed9faacb3e65cdcb301f0603551d230418301680147d9e6b0efc13e1c48ba77f61ae6021cfcda0d30630090603551d110402300030090603551d1204023000307206096086480186f842010d046516634f7267616e697a6174696f6e20496e666f726d6174696f6e204e4f542056414c4944
       EAP-Message = 0x415445442e20434c41534541
       Message-Authenticator = 0x00000000000000000000000000000000
       State = 0x869e7309849d6a16768684a64fbb490b
Finished request 10.
Going to the next request
Waking up in 3.4 seconds.
rad_recv: Access-Request packet from host 192.168.4 port 39611, id=2, length=253
Sending duplicate reply to client AP-sarlanga7 port 39611 - ID: 2
Sending Access-Challenge of id 2 to 192.168.4 port 39611
Waking up in 0.4 seconds.
Cleaning up request 0 ID 222 with timestamp +2
Cleaning up request 1 ID 223 with timestamp +2
Cleaning up request 2 ID 224 with timestamp +2
Cleaning up request 3 ID 225 with timestamp +2
Cleaning up request 4 ID 226 with timestamp +2
Cleaning up request 5 ID 227 with timestamp +2
Cleaning up request 6 ID 228 with timestamp +2
Waking up in 1.0 seconds.
Cleaning up request 7 ID 229 with timestamp +2
Waking up in 0.2 seconds.
Cleaning up request 8 ID 0 with timestamp +4
Cleaning up request 9 ID 1 with timestamp +4
Cleaning up request 10 ID 2 with timestamp +4
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.45 port 55272,
id=48, length=193
       Acct-Session-Id = "00000025-00000003"
       Acct-Status-Type = Interim-Update
       Acct-Authentic = RADIUS
       User-Name = "kiki33"
       NAS-Identifier = "AP-sarlanga4-4"
       NAS-Port = 2
       Called-Station-Id = "00-1D-7E-DC-AA-FC:sarlanga-I"
       Calling-Station-Id = "70-F1-A1-8E-D6-95"
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 54Mbps 802.11g"
       Acct-Session-Time = 2700
       Acct-Input-Packets = 4029
       Acct-Output-Packets = 2046
       Acct-Input-Octets = 564216
       Acct-Output-Octets = 1393636
       Event-Timestamp = "Dec 16 2011 09:49:57 ART"
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 2,Client-IP-Address =
192.168.45,NAS-IP-Address = 192.168.45,Acct-Session-Id =
"00000025-00000003",User-Name = "kiki33"'
[acct_unique] Acct-Unique-Session-ID = "7b9145a2626e818f".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "kiki33", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
+- entering group accounting {...}
[detail]        expand:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d
-> /usr/local/var/log/radius/radacct/192.168.45/detail-20111216
[detail] /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/192.168.45/detail-20111216
[detail]        expand: %t -> Fri Dec 16 09:49:57 2011
++[detail] returns ok
++[unix] returns noop
[radutmp]       expand: /usr/local/var/log/radius/radutmp ->
/usr/local/var/log/radius/radutmp
[radutmp]       expand: %{User-Name} -> kiki33
++[radutmp] returns ok
[attr_filter.accounting_response]       expand: %{User-Name} -> kiki33
 attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 48 to 192.168.45 port 55272
Finished request 11.
Cleaning up request 11 ID 48 with timestamp +9
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 10.129.0.60 port 53194,
id=247, length=195
       Acct-Session-Id = "4EEB32C5-00000007"
       Acct-Status-Type = Interim-Update
       Acct-Authentic = RADIUS
       User-Name = "kiki"
       NAS-Identifier = "AP-Sociales-1"
       NAS-Port = 1
       Called-Station-Id = "00-25-9C-13-FE-5E:sarlanga-I"
       Calling-Station-Id = "00-26-5E-43-22-92"
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 54Mbps 802.11g"
       Acct-Session-Time = 600
       Acct-Input-Packets = 6460
       Acct-Output-Packets = 7179
       Acct-Input-Octets = 985546
       Acct-Output-Octets = 6567171
       Event-Timestamp = "Dec 16 2011 09:49:58 ART"
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 1,Client-IP-Address =
10.129.0.60,NAS-IP-Address = 10.129.0.60,Acct-Session-Id =
"4EEB32C5-00000007",User-Name = "kiki"'
[acct_unique] Acct-Unique-Session-ID = "53fddc991168b999".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "kiki", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
+- entering group accounting {...}
[detail]        expand:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d
-> /usr/local/var/log/radius/radacct/10.129.0.60/detail-20111216
[detail] /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/10.129.0.60/detail-20111216
[detail]        expand: %t -> Fri Dec 16 09:49:58 2011
++[detail] returns ok
++[unix] returns noop
[radutmp]       expand: /usr/local/var/log/radius/radutmp ->
/usr/local/var/log/radius/radutmp
[radutmp]       expand: %{User-Name} -> kiki
++[radutmp] returns ok
[attr_filter.accounting_response]       expand: %{User-Name} -> kiki
 attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 247 to 10.129.0.60 port 53194
Finished request 12.
Cleaning up request 12 ID 247 with timestamp +10
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.2.53 port 49603,
id=160, length=189
       Acct-Session-Id = "00000025-0000000A"
       Acct-Status-Type = Interim-Update
       Acct-Authentic = RADIUS
       User-Name = "kiki333"
       NAS-Identifier = "UP-JJ-1"
       NAS-Port = 1
       Called-Station-Id = "00-1D-7E-DC-AA-D8:sarlanga-I"
       Calling-Station-Id = "18-E7-F4-6E-02-E6"
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 54Mbps 802.11g"
       Acct-Session-Time = 600
       Acct-Input-Packets = 7808
       Acct-Output-Packets = 4400
       Acct-Input-Octets = 1053849
       Acct-Output-Octets = 1392056
       Event-Timestamp = "Dec 16 2011 09:50:00 ART"
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 1,Client-IP-Address =
192.168.2.53,NAS-IP-Address = 192.168.2.53,Acct-Session-Id =
"00000025-0000000A",User-Name = "kiki333"'
[acct_unique] Acct-Unique-Session-ID = "a10966e1e5dda57e".
++[acct_unique] returns ok
[suffix] No '@' in User-Name = "kiki333", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[files] returns noop
+- entering group accounting {...}
[detail]        expand:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d
-> /usr/local/var/log/radius/radacct/192.168.2.53/detail-20111216
[detail] /usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/192.168.2.53/detail-20111216
[detail]        expand: %t -> Fri Dec 16 09:50:00 2011
++[detail] returns ok
++[unix] returns noop
[radutmp]       expand: /usr/local/var/log/radius/radutmp ->
/usr/local/var/log/radius/radutmp
[radutmp]       expand: %{User-Name} -> kiki333
++[radutmp] returns ok
[attr_filter.accounting_response]       expand: %{User-Name} -> kiki333
 attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 160 to 192.168.2.53 port 49603
Finished request 13.
Cleaning up request 13 ID 160 with timestamp +12
Going to the next request
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.4 port 39611, id=2, length=253
       User-Name = "SOYKADORNA"
       NAS-IP-Address = 127.0.0.1
       Calling-Station-Id = "02-00-00-00-00-01"
       Framed-MTU = 1400
       NAS-Port-Type = Wireless-802.11
       Connect-Info = "CONNECT 11Mbps 802.11b"
       EAP-Message =
0x0202007a198000000070160301006b0100006703014eeb3ec87be73aa918030263d5e73f349398bd48e8176a62ce944dcf0c6b95cf00003a00390038008800870035008400160013000a00330032009a009900450044002f00960041000500040015001200090014001100080006000300ff0100000400230000
       State = 0x869e7309879c6a16768684a64fbb490b
       Message-Authenticator = 0x0786010bb78d36cc0a93b73a3a9b7a0f
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]      expand: %{Virtual-Server} ->
[auth_log]      expand:
/usr/local/var/log/radius/radacct/requests/%{Client-IP-Address}/auth-detail-%{NAS-Identifier}-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d
-> /usr/local/var/log/radius/radacct/requests/192.168.4/auth-detail--DEFAULT-20111216
[auth_log] /usr/local/var/log/radius/radacct/requests/%{Client-IP-Address}/auth-detail-%{NAS-Identifier}-%{%{Virtual-Server}:-DEFAULT}-%Y%m%d
expands to /usr/local/var/log/radius/radacct/requests/192.168.4/auth-detail--DEFAULT-20111216
[auth_log]      expand: %t -> Fri Dec 16 09:50:01 2011
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "SOYKADORNA", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 length 122
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
rlm_eap: No EAP session matching the State variable.
[eap] Either EAP-request timed out OR EAP-response to an unknown EAP-request
[eap] Failed in handler
++[eap] returns invalid
Failed to authenticate the user.
Login incorrect: [SOYKADORNA] (from client AP-sarlanga7 port 0 cli
02-00-00-00-00-01)
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[attr_filter.access_reject]     expand: %{User-Name} -> SOYKADORNA
 attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 14 for 1 seconds
Going to the next request
-
--
Sergio Belkin  http://www.sergiobelkin.com
Watch More TV http://sebelk.blogspot.com
LPIC-2 Certified - http://www.lpi.org

-- 
--
Sergio Belkin  http://www.sergiobelkin.com
Watch More TV http://sebelk.blogspot.com
LPIC-2 Certified - http://www.lpi.org