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

Sergio Belkin sebelk at gmail.com
Fri Dec 16 15:48:50 CET 2011


Hi,

Sorry I resend the message because of original message was bounced
because it was 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"

I think I've found something about it

http://www.ietf.org/rfc/rfc3579.txt 2.6.3 (Conflicting message)

That could be the problem?

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




More information about the Freeradius-Users mailing list