Hi list, I have freeradius working in a EDUROAM federation, all PEAP-MSCHAPv2 and TTLS-EAP working locally, however when roaming to the federation, PEAP-MSCHAPv2 fails categorically and only TTLS-EAP works with success. eapol_test fails with WARNING: PMK mismatch Any ideas, please? Rui freeradius -X FreeRADIUS Version 2.1.10, for host i486-pc-linux-gnu, built on Nov 14 2010 at 20:41:03 Copyright (C) 1999-2009 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 /etc/freeradius/radiusd.conf including configuration file /etc/freeradius/proxy.conf including configuration file /etc/freeradius/clients.conf including files in directory /etc/freeradius/modules/ including configuration file /etc/freeradius/modules/smsotp including configuration file /etc/freeradius/modules/policy including configuration file /etc/freeradius/modules/sqlcounter_expire_on_login including configuration file /etc/freeradius/modules/counter including configuration file /etc/freeradius/modules/checkval including configuration file /etc/freeradius/modules/detail including configuration file /etc/freeradius/modules/radutmp including configuration file /etc/freeradius/modules/detail.log including configuration file /etc/freeradius/modules/ntlm_auth including configuration file /etc/freeradius/modules/mac2ip including configuration file /etc/freeradius/modules/perl including configuration file /etc/freeradius/modules/otp including configuration file /etc/freeradius/modules/ippool including configuration file /etc/freeradius/modules/linelog including configuration file /etc/freeradius/modules/detail.example.com including configuration file /etc/freeradius/modules/f_ticks including configuration file /etc/freeradius/modules/attr_rewrite including configuration file /etc/freeradius/modules/preprocess including configuration file /etc/freeradius/modules/attr_filter including configuration file /etc/freeradius/modules/always including configuration file /etc/freeradius/modules/sql_log including configuration file /etc/freeradius/modules/smbpasswd including configuration file /etc/freeradius/modules/files including configuration file /etc/freeradius/modules/unix including configuration file /etc/freeradius/modules/ldap including configuration file /etc/freeradius/modules/sradutmp including configuration file /etc/freeradius/modules/expiration including configuration file /etc/freeradius/modules/inner-eap including configuration file /etc/freeradius/modules/mschap including configuration file /etc/freeradius/modules/mac2vlan including configuration file /etc/freeradius/modules/krb5 including configuration file /etc/freeradius/modules/passwd including configuration file /etc/freeradius/modules/pam including configuration file /etc/freeradius/modules/realm including configuration file /etc/freeradius/modules/wimax including configuration file /etc/freeradius/modules/chap including configuration file /etc/freeradius/modules/exec including configuration file /etc/freeradius/modules/expr including configuration file /etc/freeradius/modules/acct_unique including configuration file /etc/freeradius/modules/cui including configuration file /etc/freeradius/modules/opendirectory including configuration file /etc/freeradius/modules/dynamic_clients including configuration file /etc/freeradius/modules/echo including configuration file /etc/freeradius/modules/etc_group including configuration file /etc/freeradius/modules/pap including configuration file /etc/freeradius/modules/logintime including configuration file /etc/freeradius/modules/digest including configuration file /etc/freeradius/eap.conf including configuration file /etc/freeradius/policy.conf including files in directory /etc/freeradius/sites-enabled/ including configuration file /etc/freeradius/sites-enabled/status including configuration file /etc/freeradius/sites-enabled/default including configuration file /etc/freeradius/sites-enabled/inner-tunnel main { user = "freerad" group = "freerad" allow_core_dumps = no } including dictionary file /etc/freeradius/dictionary main { prefix = "/usr" localstatedir = "/var" logdir = "/var/log/freeradius" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/freeradius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 256000 pidfile = "/var/run/freeradius/freeradius.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = yes log { stripped_names = no auth = yes auth_badpass = yes auth_goodpass = yes } security { max_attributes = 200 reject_delay = 0 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 2 default_fallback = no dead_time = 0 wake_all_if_all_dead = no } realm iscte.pt { } realm teste.iscte.pt { } realm ~.*\.iscte\.intranet { } realm ~.*\.iul\.intra { } realm ~.*\.iscte\.pt { } realm NULL { } realm DEFAULT { nostrip ldflag = round_robin authhost = 193.136.192.43:1812 accthost = 193.136.192.43:1813 secret = xxxxxxxx } realm DEFAULT { ldflag = round_robin authhost = 193.136.192.44:1812 accthost = 193.136.192.44:1813 secret = xxxxxxxxx } # realm DEFAULT radiusd: #### Loading Clients #### client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = "xxxxxxxx" nastype = "other" } client 193.136.188.36 { ipaddr = 193.136.188.36 netmask = 32 require_message_authenticator = no secret = "xxxxxxxxx" nastype = "other" } client 10.10.66.18/32 { ipaddr = 10.10.66.18 netmask = 32 require_message_authenticator = no secret = "wdsiscte" shortname = "nut" nastype = "other" } client 10.10.65.0/24 { require_message_authenticator = no secret = "xxx" shortname = "rede1_aps" nastype = "cisco" } client 10.10.66.0/24 { require_message_authenticator = no secret = "xxxxxxxx" shortname = "rede2_aps" nastype = "cisco" } client 10.10.32.35/32 { require_message_authenticator = no secret = "xxxxxxx" shortname = "syslog" nastype = "other" } client 193.136.192.43 { require_message_authenticator = no secret = "xxxxxxxxx" shortname = "proxyNacional1" nastype = "other" } client 193.136.192.44 { require_message_authenticator = no secret = "xxxxxxxx" shortname = "proxyNacional2" nastype = "other" } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating module "exec" from file /etc/freeradius/modules/exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating module "expr" from file /etc/freeradius/modules/expr Module: Linked to module rlm_expiration Module: Instantiating module "expiration" from file /etc/freeradius/modules/expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating module "logintime" from file /etc/freeradius/modules/logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server status { # from file /etc/freeradius/sites-enabled/status modules { Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_always Module: Instantiating module "ok" from file /etc/freeradius/modules/always always ok { rcode = "ok" simulcount = 0 mpp = no } } # modules } # server server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating module "pap" from file /etc/freeradius/modules/pap pap { encryption_scheme = "auto" auto_header = yes } Module: Linked to module rlm_chap Module: Instantiating module "chap" from file /etc/freeradius/modules/chap Module: Linked to module rlm_mschap Module: Instantiating module "mschap" from file /etc/freeradius/modules/mschap mschap { use_mppe = yes require_encryption = yes require_strong = yes with_ntdomain_hack = yes ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --username=%{%{Stripped-User-Name}:-%{User-Name:-None}} --challenge=%{mschap:Challenge:-00} --domain=IUL --nt-response=%{mschap:NT-Response:-00}" } Module: Linked to module rlm_eap Module: Instantiating module "eap" from file /etc/freeradius/eap.conf eap { default_eap_type = "peap" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 4096 } 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 = "mschap" } 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 CA_path = "/etc/freeradius/certs" pem_file_type = yes private_key_file = "/etc/freeradius/certs/server.key" certificate_file = "/etc/freeradius/certs/server.pem" CA_file = "/etc/freeradius/certs/ca.pem" private_key_password = "isctexcert" dh_file = "/etc/freeradius/certs/dh" random_file = "/dev/urandom" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" make_cert_command = "/etc/freeradius/certs/bootstrap" cache { enable = no lifetime = 24 max_entries = 255 } verify { } } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { default_eap_type = "mschapv2" copy_request_to_tunnel = yes use_tunneled_reply = no include_length = yes } 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 } 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 module "suffix" from file /etc/freeradius/modules/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_files Module: Instantiating module "files" from file /etc/freeradius/modules/files files { usersfile = "/etc/freeradius/users" acctusersfile = "/etc/freeradius/acct_users" preproxy_usersfile = "/etc/freeradius/preproxy_users" compat = "no" } [/etc/freeradius/users]:36 WARNING! Changing 'Reply-Message =' to 'Reply-Message ==' for comparing RADIUS attribute in check item list for user DEFAULT Module: Checking session {...} for more modules to load Module: Linked to module rlm_radutmp Module: Instantiating module "radutmp" from file /etc/freeradius/modules/radutmp radutmp { filename = "/var/log/freeradius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Checking pre-proxy {...} for more modules to load Module: Linked to module rlm_detail Module: Instantiating module "pre_proxy_log" from file /etc/freeradius/modules/detail.log detail pre_proxy_log { detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load Module: Instantiating module "reply_log" from file /etc/freeradius/modules/detail.log detail reply_log { detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Linked to module rlm_attr_filter Module: Instantiating module "attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter attr_filter attr_filter.access_reject { attrsfile = "/etc/freeradius/attrs.access_reject" key = "%{User-Name}" } } # modules } # server server { # from file /etc/freeradius/radiusd.conf 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 module "preprocess" from file /etc/freeradius/modules/preprocess preprocess { huntgroups = "/etc/freeradius/huntgroups" hints = "/etc/freeradius/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 module "auth_log" from file /etc/freeradius/modules/detail.log detail auth_log { detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Checking preacct {...} for more modules to load Module: Checking accounting {...} for more modules to load Module: Instantiating module "detail" from file /etc/freeradius/modules/detail detail { detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Linked to module rlm_counter Module: Instantiating module "daily" from file /etc/freeradius/modules/counter counter daily { filename = "/etc/freeradius/db.daily" key = "User-Name" reset = "daily" count-attribute = "Acct-Session-Time" counter-name = "Daily-Session-Time" check-name = "Max-Daily-Session" reply-name = "Session-Timeout" allowed-servicetype = "Framed-User" cache-size = 5000 } rlm_counter: Counter attribute Daily-Session-Time is number 11273 rlm_counter: Current Time: 1326933518 [2012-01-19 00:38:38], Next reset 1327017600 [2012-01-20 00:00:00] Module: Linked to module rlm_unix Module: Instantiating module "unix" from file /etc/freeradius/modules/unix unix { radwtmp = "/var/log/freeradius/radwtmp" } Module: Instantiating module "sradutmp" from file /etc/freeradius/modules/sradutmp radutmp sradutmp { filename = "/var/log/freeradius/sradutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 420 callerid = no } Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/modules/attr_filter attr_filter attr_filter.accounting_response { attrsfile = "/etc/freeradius/attrs.accounting_response" key = "%{User-Name}" } Module: Checking session {...} for more modules to load Module: Checking pre-proxy {...} for more modules to load Module: Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/modules/attr_filter attr_filter attr_filter.pre-proxy { attrsfile = "/etc/freeradius/attrs.pre-proxy" key = "%{Realm}" } Module: Checking post-proxy {...} for more modules to load Module: Instantiating module "post_proxy_log" from file /etc/freeradius/modules/detail.log detail post_proxy_log { detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/modules/attr_filter attr_filter attr_filter.post-proxy { attrsfile = "/etc/freeradius/attrs" key = "%{Realm}" } Module: Checking post-auth {...} for more modules to load Module: Linked to module rlm_linelog Module: Instantiating module "f_ticks" from file /etc/freeradius/modules/f_ticks linelog f_ticks { filename = "syslog" format = "" reference = "f_ticks.%{%{reply:Packet-Type}:-format}" } } # modules } # server radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = 193.136.188.36 port = 0 } listen { type = "acct" ipaddr = 193.136.188.36 port = 0 } listen { type = "status" ipaddr = * port = 18120 client admin { ipaddr = 127.0.0.1 require_message_authenticator = no secret = "xxxxxxxxxx" } client admin2 { ipaddr = 193.136.188.36 require_message_authenticator = no secret = "xxxxxxxxx" } client syslog { ipaddr = 10.10.32.35 require_message_authenticator = no secret = "xxxxxxxxx" } } listen { type = "auth" ipaddr = 127.0.0.1 port = 1812 } listen { type = "acct" ipaddr = 127.0.0.1 port = 1813 } Listening on authentication address 193.136.188.36 port 1812 Listening on accounting interface eth0 address 193.136.188.36 port 1813 Listening on status address * port 18120 as server status Listening on authentication address 127.0.0.1 port 1812 as server inner-tunnel Listening on accounting address 127.0.0.1 port 1813 as server inner-tunnel Listening on proxy address 193.136.188.36 port 1814 Ready to process requests. rad_recv: Access-Request packet from host 10.10.32.35 port 54698, id=0, length=144 User-Name = "iscte@roam.fccn.pt" 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 = 0x0200001701697363746540726f616d2e6663636e2e7074 Message-Authenticator = 0xb378f4c98f61f52c1f2d4b8e082faf8a # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} [preprocess] expand: %{NAS-IP-Address} -> 127.0.0.1 ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[auth_log] returns ok [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" [suffix] Found realm "DEFAULT" [suffix] Adding Realm = "DEFAULT" [suffix] Proxying request from user iscte to realm DEFAULT [suffix] Preparing to proxy authentication request to realm "DEFAULT" ++[suffix] returns updated ++[mschap] returns noop [eap] Request is supposed to be proxied to Realm DEFAULT. Not doing EAP. ++[eap] returns noop [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] users: Matched entry DEFAULT at line 33 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default +- entering group pre-proxy {...} [files] preproxy_users: Matched entry DEFAULT at line 22 ++[files] returns ok [attr_filter.pre-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 50 ++[attr_filter.pre-proxy] returns updated [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[pre_proxy_log] returns ok ++? if (Packet-Type != Accounting-Request) ? Evaluating (Packet-Type != Accounting-Request) -> FALSE ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 11 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x0200001701697363746540726f616d2e6663636e2e7074 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x30 Proxying request 0 to home server 193.136.192.43 port 1812 Sending Access-Request of id 11 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x0200001701697363746540726f616d2e6663636e2e7074 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x30 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 193.136.192.43 port 1812, id=11, length=49 EAP-Message = 0x010100061921 Message-Authenticator = 0x0c5de835cf089be1f659f1086a645eea Proxy-State = 0x30 # Executing section post-proxy from file /etc/freeradius/sites-enabled/default +- entering group post-proxy {...} [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[post_proxy_log] returns ok [attr_filter.post-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 103 ++[attr_filter.post-proxy] returns updated [eap] No pre-existing handler found ++[eap] returns noop Sending Access-Challenge of id 0 to 10.10.32.35 port 54698 EAP-Message = 0x010100061921 Message-Authenticator = 0x00000000000000000000000000000000 Finished request 0. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.10.32.35 port 54698, id=1, length=222 User-Name = "iscte@roam.fccn.pt" 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 = 0x020100651901160301005a0100005603014f176610df0229e267ffe1c5836f1caf144fef291958cace7536caa945b100de00002800390038003500160013000a00330032002f000500040015001200090014001100080006000300ff020100000400230000 Message-Authenticator = 0x8b1eebe285cde02120a86afaa0121199 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} [preprocess] expand: %{NAS-IP-Address} -> 127.0.0.1 ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[auth_log] returns ok [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" [suffix] Found realm "DEFAULT" [suffix] Adding Realm = "DEFAULT" [suffix] Proxying request from user iscte to realm DEFAULT [suffix] Preparing to proxy authentication request to realm "DEFAULT" ++[suffix] returns updated ++[mschap] returns noop [eap] Request is supposed to be proxied to Realm DEFAULT. Not doing EAP. ++[eap] returns noop [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] users: Matched entry DEFAULT at line 33 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default +- entering group pre-proxy {...} [files] preproxy_users: Matched entry DEFAULT at line 22 ++[files] returns ok [attr_filter.pre-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 50 ++[attr_filter.pre-proxy] returns updated [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[pre_proxy_log] returns ok ++? if (Packet-Type != Accounting-Request) ? Evaluating (Packet-Type != Accounting-Request) -> FALSE ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 152 to 193.136.192.44 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x020100651901160301005a0100005603014f176610df0229e267ffe1c5836f1caf144fef291958cace7536caa945b100de00002800390038003500160013000a00330032002f000500040015001200090014001100080006000300ff020100000400230000 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x31 Proxying request 1 to home server 193.136.192.44 port 1812 Sending Access-Request of id 152 to 193.136.192.44 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x020100651901160301005a0100005603014f176610df0229e267ffe1c5836f1caf144fef291958cace7536caa945b100de00002800390038003500160013000a00330032002f000500040015001200090014001100080006000300ff020100000400230000 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x31 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 193.136.192.44 port 1812, id=152, length=1059 EAP-Message = 0x010203f219c10000067b160301004a0200004603014f1766100a5cca8828dd07fd8c05f3c33a6a52b6e10d1707dbdf621a39b799a02084471ff4c4f04f6c0c4c1bf2fa2e9479ffa6c41501a2e27407dfa5e36b834bd3003500160301061e0b00061a00061700033a308203363082021ea003020102020109300d06092a864886f70d01010405003020311e301c06092a864886f70d010901160f7073696d6f6573406663636e2e7074301e170d3035303231353136313133385a170d3037303230353136313133385a308183311e301c060355040313157261642d63762d7465737465732e6663636e2e7074310f300d060355040813064c6973626f61 EAP-Message = 0x310b3009060355040613025054311e301c06092a864886f70d010901160f7073696d6f6573406663636e2e7074310d300b060355040a13044643434e31143012060355040b130b54656c656d617469636f7330820122300d06092a864886f70d01010105000382010f003082010a02820101009c3e40c696ba2d597354f1dcafac4b6fc97bdd38cd228f08b5a1f893598759e54e9450b8c4062172fe5fdc3bd1d8a4fef200944296214cae2544d7bc9a552f468a32caf7a730b063df202bc0a0eff27dd8dd24ec2a4b212ba9f7d2a601170c43fce341ad68912b827d414c5ebe05db1b1fcead3d68aabbe4bcfa4a60a2d836e4105e8732dffc7784e5c0 EAP-Message = 0x0bdcb95819111e89b81cda83e9bd6d73105d2434ed277253aa688724a924edc13d2a37172ed30faf408126076d889b1afc72d6f6ebfc14c16ffe0b6180bc94cd86c0e8f81cdc762ff86f8804fb80b9b7727473fbaa274d01e999dee32981e8edbbb9b1a68903cf0ca6f61a2c960b0a4a79bbc7c41e1d0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010405000382010100c56cce4f5641ec0b806b376e95953b6e9aa0b24e185d4ebd388c2872abecbc27c74d345d4e3ebed725146497e9fd00e0fbf6d0ecbf051217452a67c14e97f300757deaf03a24d8d83988958c0159bd302705c8523a EAP-Message = 0x0a97b9214ba63bfb06f792989856fe53ec6fb99793b35e8dfc75984777a678537758dd5c527a9dae2c77339ccb61a71c3a22ac54031a36991bb582832769a4a9656af18a04f41053e0e59f910dbc708261d749e3ccccef861d6b44536e9016d78b22472e7d53b30e1f24010fce864e126ab4fb5453b5991aa9d677dc66d804c0da9a12275d38ebc4d7ac2c8693a912e49d134f01731b16ec39f53bffd2c0784e443b59f9dd718ed13bf2500002d7308202d3308201bba003020102020900cf11a40b54c230de300d06092a864886f70d01010405003020311e301c06092a864886f70d010901160f7073696d6f6573406663636e2e7074301e170d Message-Authenticator = 0x9107528c5865d65b3e530d7f8a30c6b0 Proxy-State = 0x31 # Executing section post-proxy from file /etc/freeradius/sites-enabled/default +- entering group post-proxy {...} [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[post_proxy_log] returns ok [attr_filter.post-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 103 ++[attr_filter.post-proxy] returns updated [eap] No pre-existing handler found ++[eap] returns noop Sending Access-Challenge of id 1 to 10.10.32.35 port 54698 EAP-Message = 0x010203f219c10000067b160301004a0200004603014f1766100a5cca8828dd07fd8c05f3c33a6a52b6e10d1707dbdf621a39b799a02084471ff4c4f04f6c0c4c1bf2fa2e9479ffa6c41501a2e27407dfa5e36b834bd3003500160301061e0b00061a00061700033a308203363082021ea003020102020109300d06092a864886f70d01010405003020311e301c06092a864886f70d010901160f7073696d6f6573406663636e2e7074301e170d3035303231353136313133385a170d3037303230353136313133385a308183311e301c060355040313157261642d63762d7465737465732e6663636e2e7074310f300d060355040813064c6973626f61 EAP-Message = 0x310b3009060355040613025054311e301c06092a864886f70d010901160f7073696d6f6573406663636e2e7074310d300b060355040a13044643434e31143012060355040b130b54656c656d617469636f7330820122300d06092a864886f70d01010105000382010f003082010a02820101009c3e40c696ba2d597354f1dcafac4b6fc97bdd38cd228f08b5a1f893598759e54e9450b8c4062172fe5fdc3bd1d8a4fef200944296214cae2544d7bc9a552f468a32caf7a730b063df202bc0a0eff27dd8dd24ec2a4b212ba9f7d2a601170c43fce341ad68912b827d414c5ebe05db1b1fcead3d68aabbe4bcfa4a60a2d836e4105e8732dffc7784e5c0 EAP-Message = 0x0bdcb95819111e89b81cda83e9bd6d73105d2434ed277253aa688724a924edc13d2a37172ed30faf408126076d889b1afc72d6f6ebfc14c16ffe0b6180bc94cd86c0e8f81cdc762ff86f8804fb80b9b7727473fbaa274d01e999dee32981e8edbbb9b1a68903cf0ca6f61a2c960b0a4a79bbc7c41e1d0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010405000382010100c56cce4f5641ec0b806b376e95953b6e9aa0b24e185d4ebd388c2872abecbc27c74d345d4e3ebed725146497e9fd00e0fbf6d0ecbf051217452a67c14e97f300757deaf03a24d8d83988958c0159bd302705c8523a EAP-Message = 0x0a97b9214ba63bfb06f792989856fe53ec6fb99793b35e8dfc75984777a678537758dd5c527a9dae2c77339ccb61a71c3a22ac54031a36991bb582832769a4a9656af18a04f41053e0e59f910dbc708261d749e3ccccef861d6b44536e9016d78b22472e7d53b30e1f24010fce864e126ab4fb5453b5991aa9d677dc66d804c0da9a12275d38ebc4d7ac2c8693a912e49d134f01731b16ec39f53bffd2c0784e443b59f9dd718ed13bf2500002d7308202d3308201bba003020102020900cf11a40b54c230de300d06092a864886f70d01010405003020311e301c06092a864886f70d010901160f7073696d6f6573406663636e2e7074301e170d Message-Authenticator = 0x00000000000000000000000000000000 Finished request 1. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.10.32.35 port 54698, id=2, length=127 User-Name = "iscte@roam.fccn.pt" 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 = 0x020200061901 Message-Authenticator = 0xb3a708c8077b9af3c3a3ec432f954334 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} [preprocess] expand: %{NAS-IP-Address} -> 127.0.0.1 ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[auth_log] returns ok [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" [suffix] Found realm "DEFAULT" [suffix] Adding Realm = "DEFAULT" [suffix] Proxying request from user iscte to realm DEFAULT [suffix] Preparing to proxy authentication request to realm "DEFAULT" ++[suffix] returns updated ++[mschap] returns noop [eap] Request is supposed to be proxied to Realm DEFAULT. Not doing EAP. ++[eap] returns noop [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] users: Matched entry DEFAULT at line 33 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default +- entering group pre-proxy {...} [files] preproxy_users: Matched entry DEFAULT at line 22 ++[files] returns ok [attr_filter.pre-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 50 ++[attr_filter.pre-proxy] returns updated [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[pre_proxy_log] returns ok ++? if (Packet-Type != Accounting-Request) ? Evaluating (Packet-Type != Accounting-Request) -> FALSE ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 82 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x020200061901 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x32 Proxying request 2 to home server 193.136.192.43 port 1812 Sending Access-Request of id 82 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x020200061901 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x32 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 193.136.192.43 port 1812, id=82, length=712 EAP-Message = 0x0103029919013035303231353134343531395a170d3036303231353134343531395a3020311e301c06092a864886f70d010901160f7073696d6f6573406663636e2e707430820122300d06092a864886f70d01010105000382010f003082010a0282010100ce05f673daef56db29f8b2715f3d9505f0db08d7dad15bf7c12e3496e2ce999154183e5062ef8afe1cf24497e23281ad74ed31d7b45c333c212ac854e249038b25f93981cbf82437e790a9ef7d510bc5a9101f5050d1bd32d403b90e4f930bad3f3ce7bcc37b3021b3bc34ec80c109fbe5dd2f07dcfef8383caa369b777b644f29b7f209316bc81960db25dd19ce05258785bdd40756cb05 EAP-Message = 0xdbbaf40897fa98fed6868c4078f34948d7c397249511e2ddaf1f0cb03f13e8511da742fb4616ac9fad9b9e613b05e2509cfda212b49643c993c05fc1dbe5b523d0b4b33ba3deb600d0f8f6cbcf32e41263b81707d92e5e8071cd1859f27c094d67ebbe6e3c079f750203010001a310300e300c0603551d13040530030101ff300d06092a864886f70d01010405000382010100113b6fb8cb0a394278f35a5d118cb987707800080a3633a4d0658d86f000e46a7eaad5136afecb910f5d6517fe36878c5f81248f388561db0f027eb21c26037baf28412a0885fffc8ed64d927b9df26ac39f0002bb067335631061475f642e66a3366af14ca9559737c0 EAP-Message = 0xa27462412ca6e60674a1b0c4c8d0d478a3b4552684974693fbad3870bfef259ad1ab683d6d50fa354e14025bb381e22fa72649dc33fa76dc12526e469efe39df0c24aef596a8464b3e5ab1476744b5fbeb6c427d663f8eb1bc10499b1db428b77c590a00a1e9f085c5a7db25f6521e8c93939b25f7d8ff90024e93fdc04a565483763e7860b35956a6810875c451b36dcb40e5c01c5a16030100040e000000 Message-Authenticator = 0x3586ca38fba28faa29b3258f9167fa98 Proxy-State = 0x32 # Executing section post-proxy from file /etc/freeradius/sites-enabled/default +- entering group post-proxy {...} [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[post_proxy_log] returns ok [attr_filter.post-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 103 ++[attr_filter.post-proxy] returns updated [eap] No pre-existing handler found ++[eap] returns noop Sending Access-Challenge of id 2 to 10.10.32.35 port 54698 EAP-Message = 0x0103029919013035303231353134343531395a170d3036303231353134343531395a3020311e301c06092a864886f70d010901160f7073696d6f6573406663636e2e707430820122300d06092a864886f70d01010105000382010f003082010a0282010100ce05f673daef56db29f8b2715f3d9505f0db08d7dad15bf7c12e3496e2ce999154183e5062ef8afe1cf24497e23281ad74ed31d7b45c333c212ac854e249038b25f93981cbf82437e790a9ef7d510bc5a9101f5050d1bd32d403b90e4f930bad3f3ce7bcc37b3021b3bc34ec80c109fbe5dd2f07dcfef8383caa369b777b644f29b7f209316bc81960db25dd19ce05258785bdd40756cb05 EAP-Message = 0xdbbaf40897fa98fed6868c4078f34948d7c397249511e2ddaf1f0cb03f13e8511da742fb4616ac9fad9b9e613b05e2509cfda212b49643c993c05fc1dbe5b523d0b4b33ba3deb600d0f8f6cbcf32e41263b81707d92e5e8071cd1859f27c094d67ebbe6e3c079f750203010001a310300e300c0603551d13040530030101ff300d06092a864886f70d01010405000382010100113b6fb8cb0a394278f35a5d118cb987707800080a3633a4d0658d86f000e46a7eaad5136afecb910f5d6517fe36878c5f81248f388561db0f027eb21c26037baf28412a0885fffc8ed64d927b9df26ac39f0002bb067335631061475f642e66a3366af14ca9559737c0 EAP-Message = 0xa27462412ca6e60674a1b0c4c8d0d478a3b4552684974693fbad3870bfef259ad1ab683d6d50fa354e14025bb381e22fa72649dc33fa76dc12526e469efe39df0c24aef596a8464b3e5ab1476744b5fbeb6c427d663f8eb1bc10499b1db428b77c590a00a1e9f085c5a7db25f6521e8c93939b25f7d8ff90024e93fdc04a565483763e7860b35956a6810875c451b36dcb40e5c01c5a16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 Finished request 2. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 10.10.32.35 port 54698, id=3, length=455 User-Name = "iscte@roam.fccn.pt" 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 = 0x0203014c190116030101061000010201000d53c1f5bbd701b2401967c46aca7d1328d4fb8789a4d185c0075099020cc3201d476a61f3ed688b7ecd12120462fbc7c60d4ef89e44320092845176984a44b4111894c7d19807ec2b6d101e9f73510fb08674449d988fd14776e96057170d258b549ba9cbd0c0259daa8b451e9290821243c50f4479fd05dfa06d991acf4ca97a8456339d3fe249fc126f6ad9b69a896e463b678eebee1b3b734d1bdff574cd5eac102185d15d7d5acb290f9adbaf8f5611a2bd0e9efc59aec2593c1961c453e114cdd10ef61070f1e6d1d97d858f4023e213ad4533504ed39678f58d4ec71709b4eb8b89b1bbfcdef21f19 EAP-Message = 0x882e99cf4dcbd8a1e423ff26c727e496f0eaae6e1403010001011603010030b0a10953547cd6d5abdd0494bc58bb41cc2dedcd940bb07753b0448440b7147a59359686a34c3327fac137ab46459474 Message-Authenticator = 0xdeba7e496bff31e141133bc7358a056c # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} [preprocess] expand: %{NAS-IP-Address} -> 127.0.0.1 ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[auth_log] returns ok [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" [suffix] Found realm "DEFAULT" [suffix] Adding Realm = "DEFAULT" [suffix] Proxying request from user iscte to realm DEFAULT [suffix] Preparing to proxy authentication request to realm "DEFAULT" ++[suffix] returns updated ++[mschap] returns noop [eap] Request is supposed to be proxied to Realm DEFAULT. Not doing EAP. ++[eap] returns noop [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] users: Matched entry DEFAULT at line 33 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default +- entering group pre-proxy {...} [files] preproxy_users: Matched entry DEFAULT at line 22 ++[files] returns ok [attr_filter.pre-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 50 ++[attr_filter.pre-proxy] returns updated [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[pre_proxy_log] returns ok ++? if (Packet-Type != Accounting-Request) ? Evaluating (Packet-Type != Accounting-Request) -> FALSE ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 247 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x0203014c190116030101061000010201000d53c1f5bbd701b2401967c46aca7d1328d4fb8789a4d185c0075099020cc3201d476a61f3ed688b7ecd12120462fbc7c60d4ef89e44320092845176984a44b4111894c7d19807ec2b6d101e9f73510fb08674449d988fd14776e96057170d258b549ba9cbd0c0259daa8b451e9290821243c50f4479fd05dfa06d991acf4ca97a8456339d3fe249fc126f6ad9b69a896e463b678eebee1b3b734d1bdff574cd5eac102185d15d7d5acb290f9adbaf8f5611a2bd0e9efc59aec2593c1961c453e114cdd10ef61070f1e6d1d97d858f4023e213ad4533504ed39678f58d4ec71709b4eb8b89b1bbfcdef21f19 EAP-Message = 0x882e99cf4dcbd8a1e423ff26c727e496f0eaae6e1403010001011603010030b0a10953547cd6d5abdd0494bc58bb41cc2dedcd940bb07753b0448440b7147a59359686a34c3327fac137ab46459474 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x33 Proxying request 3 to home server 193.136.192.43 port 1812 Sending Access-Request of id 247 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x0203014c190116030101061000010201000d53c1f5bbd701b2401967c46aca7d1328d4fb8789a4d185c0075099020cc3201d476a61f3ed688b7ecd12120462fbc7c60d4ef89e44320092845176984a44b4111894c7d19807ec2b6d101e9f73510fb08674449d988fd14776e96057170d258b549ba9cbd0c0259daa8b451e9290821243c50f4479fd05dfa06d991acf4ca97a8456339d3fe249fc126f6ad9b69a896e463b678eebee1b3b734d1bdff574cd5eac102185d15d7d5acb290f9adbaf8f5611a2bd0e9efc59aec2593c1961c453e114cdd10ef61070f1e6d1d97d858f4023e213ad4533504ed39678f58d4ec71709b4eb8b89b1bbfcdef21f19 EAP-Message = 0x882e99cf4dcbd8a1e423ff26c727e496f0eaae6e1403010001011603010030b0a10953547cd6d5abdd0494bc58bb41cc2dedcd940bb07753b0448440b7147a59359686a34c3327fac137ab46459474 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x33 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 193.136.192.43 port 1812, id=247, length=112 EAP-Message = 0x0104004519810000003b1403010001011603010030f6250ffe4af8eb309670c5b5dc4fac567ca0e4e1afe64e0d04ec35d2e87fdfce0ab291bc69225e1737ce03bdd25e4961 Message-Authenticator = 0x94cd6d3a20a4e5f09fa252f8533ca7ce Proxy-State = 0x33 # Executing section post-proxy from file /etc/freeradius/sites-enabled/default +- entering group post-proxy {...} [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] expand: %t -> Thu Jan 19 00:38:40 2012 ++[post_proxy_log] returns ok [attr_filter.post-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 103 ++[attr_filter.post-proxy] returns updated [eap] No pre-existing handler found ++[eap] returns noop Sending Access-Challenge of id 3 to 10.10.32.35 port 54698 EAP-Message = 0x0104004519810000003b1403010001011603010030f6250ffe4af8eb309670c5b5dc4fac567ca0e4e1afe64e0d04ec35d2e87fdfce0ab291bc69225e1737ce03bdd25e4961 Message-Authenticator = 0x00000000000000000000000000000000 Finished request 3. Going to the next request Waking up in 4.7 seconds. rad_recv: Access-Request packet from host 10.10.32.35 port 54698, id=4, length=127 User-Name = "iscte@roam.fccn.pt" 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 = 0x020400061901 Message-Authenticator = 0xcf8dda9c719ed938c22d5945a4ef5d14 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} [preprocess] expand: %{NAS-IP-Address} -> 127.0.0.1 ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[auth_log] returns ok [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" [suffix] Found realm "DEFAULT" [suffix] Adding Realm = "DEFAULT" [suffix] Proxying request from user iscte to realm DEFAULT [suffix] Preparing to proxy authentication request to realm "DEFAULT" ++[suffix] returns updated ++[mschap] returns noop [eap] Request is supposed to be proxied to Realm DEFAULT. Not doing EAP. ++[eap] returns noop [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] users: Matched entry DEFAULT at line 33 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default +- entering group pre-proxy {...} [files] preproxy_users: Matched entry DEFAULT at line 22 ++[files] returns ok [attr_filter.pre-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 50 ++[attr_filter.pre-proxy] returns updated [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[pre_proxy_log] returns ok ++? if (Packet-Type != Accounting-Request) ? Evaluating (Packet-Type != Accounting-Request) -> FALSE ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 84 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x020400061901 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x34 Proxying request 4 to home server 193.136.192.43 port 1812 Sending Access-Request of id 84 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x020400061901 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x34 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 193.136.192.43 port 1812, id=84, length=86 EAP-Message = 0x0105002b19011703010020210be414821859dded4b7d1093af406a8ee2e32f20ae59da7a43cf56fe1d6364 Message-Authenticator = 0x2527e9037a2ca28c60035fe55af2035d Proxy-State = 0x34 # Executing section post-proxy from file /etc/freeradius/sites-enabled/default +- entering group post-proxy {...} [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[post_proxy_log] returns ok [attr_filter.post-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 103 ++[attr_filter.post-proxy] returns updated [eap] No pre-existing handler found ++[eap] returns noop Sending Access-Challenge of id 4 to 10.10.32.35 port 54698 EAP-Message = 0x0105002b19011703010020210be414821859dded4b7d1093af406a8ee2e32f20ae59da7a43cf56fe1d6364 Message-Authenticator = 0x00000000000000000000000000000000 Finished request 4. Going to the next request Waking up in 4.6 seconds. rad_recv: Access-Request packet from host 10.10.32.35 port 54698, id=5, length=217 User-Name = "iscte@roam.fccn.pt" 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 = 0x02050060190117030100203dea7ea4a4dfa23bb763bfe8adfbd8bb5c6207daa4eb29fd32ec28d6244ad5d51703010030ae10e31e9f14ce15b57a6f127bdc753c2ea9dbe23091ddbaa9f06f3bc4fa25520039462ae0d42790bba24b76146d1ba7 Message-Authenticator = 0x4037aa0d8abfe12ad773611d3fd3916d # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} [preprocess] expand: %{NAS-IP-Address} -> 127.0.0.1 ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[auth_log] returns ok [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" [suffix] Found realm "DEFAULT" [suffix] Adding Realm = "DEFAULT" [suffix] Proxying request from user iscte to realm DEFAULT [suffix] Preparing to proxy authentication request to realm "DEFAULT" ++[suffix] returns updated ++[mschap] returns noop [eap] Request is supposed to be proxied to Realm DEFAULT. Not doing EAP. ++[eap] returns noop [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] users: Matched entry DEFAULT at line 33 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default +- entering group pre-proxy {...} [files] preproxy_users: Matched entry DEFAULT at line 22 ++[files] returns ok [attr_filter.pre-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 50 ++[attr_filter.pre-proxy] returns updated [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[pre_proxy_log] returns ok ++? if (Packet-Type != Accounting-Request) ? Evaluating (Packet-Type != Accounting-Request) -> FALSE ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 148 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x02050060190117030100203dea7ea4a4dfa23bb763bfe8adfbd8bb5c6207daa4eb29fd32ec28d6244ad5d51703010030ae10e31e9f14ce15b57a6f127bdc753c2ea9dbe23091ddbaa9f06f3bc4fa25520039462ae0d42790bba24b76146d1ba7 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x35 Proxying request 5 to home server 193.136.192.43 port 1812 Sending Access-Request of id 148 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x02050060190117030100203dea7ea4a4dfa23bb763bfe8adfbd8bb5c6207daa4eb29fd32ec28d6244ad5d51703010030ae10e31e9f14ce15b57a6f127bdc753c2ea9dbe23091ddbaa9f06f3bc4fa25520039462ae0d42790bba24b76146d1ba7 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x35 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 193.136.192.43 port 1812, id=148, length=134 EAP-Message = 0x0106005b19011703010050d731723127c1370ee69c3184dc7247676f1cb3627cb4881774d42f6fb5af0f28b5ca26cbcb3b9a58e0b290394ceefad075de1e7e2025aa2c3cdb2b30d36162c5bd7d5578f009e266d49e5269020e02e9 Message-Authenticator = 0x75e11cf3fbd80a0794796c24c11188fe Proxy-State = 0x35 # Executing section post-proxy from file /etc/freeradius/sites-enabled/default +- entering group post-proxy {...} [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[post_proxy_log] returns ok [attr_filter.post-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 103 ++[attr_filter.post-proxy] returns updated [eap] No pre-existing handler found ++[eap] returns noop Sending Access-Challenge of id 5 to 10.10.32.35 port 54698 EAP-Message = 0x0106005b19011703010050d731723127c1370ee69c3184dc7247676f1cb3627cb4881774d42f6fb5af0f28b5ca26cbcb3b9a58e0b290394ceefad075de1e7e2025aa2c3cdb2b30d36162c5bd7d5578f009e266d49e5269020e02e9 Message-Authenticator = 0x00000000000000000000000000000000 Finished request 5. Going to the next request Waking up in 4.6 seconds. rad_recv: Access-Request packet from host 10.10.32.35 port 54698, id=6, length=281 User-Name = "iscte@roam.fccn.pt" 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 = 0x020600a019011703010020907b15334fd3661dec0688ea2df44bb0dcc03fefa44a70ee065becbc2349fd9e1703010070d2e6757f4fdd6dee3505732a662667e041ed4a6029fa88cf9affa8b66866ee2b9cf79586306d7a69133770a26c4abd2b349b75c6a9adf88e5d80499af2d78a5f8308dcb950b18fb86ffb175e9c381fd52ff8e90293334e8e4f0cb852b61b18298e9acff16a51924a226da2e19233819f Message-Authenticator = 0x33618019522f749b8ff3e975353293d0 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} [preprocess] expand: %{NAS-IP-Address} -> 127.0.0.1 ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[auth_log] returns ok [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" [suffix] Found realm "DEFAULT" [suffix] Adding Realm = "DEFAULT" [suffix] Proxying request from user iscte to realm DEFAULT [suffix] Preparing to proxy authentication request to realm "DEFAULT" ++[suffix] returns updated ++[mschap] returns noop [eap] Request is supposed to be proxied to Realm DEFAULT. Not doing EAP. ++[eap] returns noop [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] users: Matched entry DEFAULT at line 33 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default +- entering group pre-proxy {...} [files] preproxy_users: Matched entry DEFAULT at line 22 ++[files] returns ok [attr_filter.pre-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 50 ++[attr_filter.pre-proxy] returns updated [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[pre_proxy_log] returns ok ++? if (Packet-Type != Accounting-Request) ? Evaluating (Packet-Type != Accounting-Request) -> FALSE ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 45 to 193.136.192.44 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x020600a019011703010020907b15334fd3661dec0688ea2df44bb0dcc03fefa44a70ee065becbc2349fd9e1703010070d2e6757f4fdd6dee3505732a662667e041ed4a6029fa88cf9affa8b66866ee2b9cf79586306d7a69133770a26c4abd2b349b75c6a9adf88e5d80499af2d78a5f8308dcb950b18fb86ffb175e9c381fd52ff8e90293334e8e4f0cb852b61b18298e9acff16a51924a226da2e19233819f Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x36 Proxying request 6 to home server 193.136.192.44 port 1812 Sending Access-Request of id 45 to 193.136.192.44 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x020600a019011703010020907b15334fd3661dec0688ea2df44bb0dcc03fefa44a70ee065becbc2349fd9e1703010070d2e6757f4fdd6dee3505732a662667e041ed4a6029fa88cf9affa8b66866ee2b9cf79586306d7a69133770a26c4abd2b349b75c6a9adf88e5d80499af2d78a5f8308dcb950b18fb86ffb175e9c381fd52ff8e90293334e8e4f0cb852b61b18298e9acff16a51924a226da2e19233819f Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x36 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 193.136.192.44 port 1812, id=45, length=150 EAP-Message = 0x0107006b19011703010060018d1315db07a0adb97a0c64829e8017c4e52aa093646643571c4ff0bd35a294d0bfaa167797f3061a1ce1e67fc96dc0f28ca007b75916e418efa49e0f48653e3686bacd759ee3e8fb4023846e891ccad879fc46d7b6259cb0f88bfb4812cbee Message-Authenticator = 0xdcd3c949d421cfecd62311386b6b9b7e Proxy-State = 0x36 # Executing section post-proxy from file /etc/freeradius/sites-enabled/default +- entering group post-proxy {...} [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[post_proxy_log] returns ok [attr_filter.post-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 103 ++[attr_filter.post-proxy] returns updated [eap] No pre-existing handler found ++[eap] returns noop Sending Access-Challenge of id 6 to 10.10.32.35 port 54698 EAP-Message = 0x0107006b19011703010060018d1315db07a0adb97a0c64829e8017c4e52aa093646643571c4ff0bd35a294d0bfaa167797f3061a1ce1e67fc96dc0f28ca007b75916e418efa49e0f48653e3686bacd759ee3e8fb4023846e891ccad879fc46d7b6259cb0f88bfb4812cbee Message-Authenticator = 0x00000000000000000000000000000000 Finished request 6. Going to the next request Waking up in 4.5 seconds. rad_recv: Access-Request packet from host 10.10.32.35 port 54698, id=7, length=201 User-Name = "iscte@roam.fccn.pt" 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 = 0x02070050190117030100204b15515d5367b3f3acd1c9a787941b8b7a247bd23b7c8d70878ce8590f61437d1703010020229ac8146f0f11eb5cefb90b3d802a09cfba190846711a56b3c360cc2a86d1c0 Message-Authenticator = 0x7178d134e3b78d8339ffff7a50baacf4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} [preprocess] expand: %{NAS-IP-Address} -> 127.0.0.1 ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[auth_log] returns ok [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" [suffix] Found realm "DEFAULT" [suffix] Adding Realm = "DEFAULT" [suffix] Proxying request from user iscte to realm DEFAULT [suffix] Preparing to proxy authentication request to realm "DEFAULT" ++[suffix] returns updated ++[mschap] returns noop [eap] Request is supposed to be proxied to Realm DEFAULT. Not doing EAP. ++[eap] returns noop [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] users: Matched entry DEFAULT at line 33 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default +- entering group pre-proxy {...} [files] preproxy_users: Matched entry DEFAULT at line 22 ++[files] returns ok [attr_filter.pre-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 50 ++[attr_filter.pre-proxy] returns updated [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[pre_proxy_log] returns ok ++? if (Packet-Type != Accounting-Request) ? Evaluating (Packet-Type != Accounting-Request) -> FALSE ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 148 to 193.136.192.44 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x02070050190117030100204b15515d5367b3f3acd1c9a787941b8b7a247bd23b7c8d70878ce8590f61437d1703010020229ac8146f0f11eb5cefb90b3d802a09cfba190846711a56b3c360cc2a86d1c0 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x37 Proxying request 7 to home server 193.136.192.44 port 1812 Sending Access-Request of id 148 to 193.136.192.44 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x02070050190117030100204b15515d5367b3f3acd1c9a787941b8b7a247bd23b7c8d70878ce8590f61437d1703010020229ac8146f0f11eb5cefb90b3d802a09cfba190846711a56b3c360cc2a86d1c0 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x37 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Challenge packet from host 193.136.192.44 port 1812, id=148, length=86 EAP-Message = 0x0108002b190117030100207fcf05f4a42eb2fecbb6844e6173619a189dcd53bdb2be73730eb58dec1c99ab Message-Authenticator = 0x39dbb8e3f6f0c4fdb0ce33785472a258 Proxy-State = 0x37 # Executing section post-proxy from file /etc/freeradius/sites-enabled/default +- entering group post-proxy {...} [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[post_proxy_log] returns ok [attr_filter.post-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 103 ++[attr_filter.post-proxy] returns updated [eap] No pre-existing handler found ++[eap] returns noop Sending Access-Challenge of id 7 to 10.10.32.35 port 54698 EAP-Message = 0x0108002b190117030100207fcf05f4a42eb2fecbb6844e6173619a189dcd53bdb2be73730eb58dec1c99ab Message-Authenticator = 0x00000000000000000000000000000000 Finished request 7. Going to the next request Waking up in 4.4 seconds. rad_recv: Access-Request packet from host 10.10.32.35 port 54698, id=8, length=201 User-Name = "iscte@roam.fccn.pt" 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 = 0x02080050190117030100200b201149298fee1f4b26239cb5309386ce06458aebcefa05bce85979a26f575c17030100207bb51a418ab3fa095f1a554bc4887bf7ddf7433ccd4fa94be20bf2f8b9d1937b Message-Authenticator = 0x194258cd9632b957d30ac0435329f029 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} [preprocess] expand: %{NAS-IP-Address} -> 127.0.0.1 ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/auth-detail-20120119 [auth_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[auth_log] returns ok [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" [suffix] Found realm "DEFAULT" [suffix] Adding Realm = "DEFAULT" [suffix] Proxying request from user iscte to realm DEFAULT [suffix] Preparing to proxy authentication request to realm "DEFAULT" ++[suffix] returns updated ++[mschap] returns noop [eap] Request is supposed to be proxied to Realm DEFAULT. Not doing EAP. ++[eap] returns noop [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] expand: %{Realm} -> DEFAULT [files] users: Matched entry DEFAULT at line 33 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default +- entering group pre-proxy {...} [files] preproxy_users: Matched entry DEFAULT at line 22 ++[files] returns ok [attr_filter.pre-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 50 ++[attr_filter.pre-proxy] returns updated [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/pre-proxy-detail-20120119 [pre_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[pre_proxy_log] returns ok ++? if (Packet-Type != Accounting-Request) ? Evaluating (Packet-Type != Accounting-Request) -> FALSE ++? if (Packet-Type != Accounting-Request) -> FALSE Sending Access-Request of id 123 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x02080050190117030100200b201149298fee1f4b26239cb5309386ce06458aebcefa05bce85979a26f575c17030100207bb51a418ab3fa095f1a554bc4887bf7ddf7433ccd4fa94be20bf2f8b9d1937b Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x38 Proxying request 8 to home server 193.136.192.43 port 1812 Sending Access-Request of id 123 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address := 193.136.188.36 Calling-Station-Id = "02-00-00-00-00-01" EAP-Message = 0x02080050190117030100200b201149298fee1f4b26239cb5309386ce06458aebcefa05bce85979a26f575c17030100207bb51a418ab3fa095f1a554bc4887bf7ddf7433ccd4fa94be20bf2f8b9d1937b Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x38 Going to the next request Waking up in 0.9 seconds. rad_recv: Access-Accept packet from host 193.136.192.43 port 1812, id=123, length=183 EAP-Message = 0x03080004 Message-Authenticator = 0x0cecb037cea0c4ce65a51df6f54b8a9e User-Name = "iscte@roam.fccn.pt" MS-MPPE-Send-Key = 0x9f48986d9d7e83edf67644bb52eebef557ac5978ae225052f6ef4abb7c5ca887 MS-MPPE-Recv-Key = 0xdb3285e803da7a0cbc29978eebf74ba8d2e66fafb2ba794e26916ea02f288a9a Proxy-State = 0x38 # Executing section post-proxy from file /etc/freeradius/sites-enabled/default +- entering group post-proxy {...} [post_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/post-proxy-detail-20120119 [post_proxy_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[post_proxy_log] returns ok [attr_filter.post-proxy] expand: %{Realm} -> DEFAULT attr_filter: Matched entry DEFAULT at line 103 ++[attr_filter.post-proxy] returns updated [eap] No pre-existing handler found ++[eap] returns noop Found Auth-Type = Accept Auth-Type = Accept, accepting the user Login OK: [iscte@roam.fccn.pt/<no User-Password attribute>] (from client syslog port 0 cli 02-00-00-00-00-01) # Executing section post-auth from file /etc/freeradius/sites-enabled/default +- entering group post-auth {...} [reply_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.32.35/reply-detail-20120119 [reply_log] /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.32.35/reply-detail-20120119 [reply_log] expand: %t -> Thu Jan 19 00:38:41 2012 ++[reply_log] returns ok [f_ticks] expand: %{reply:Packet-Type} -> Access-Accept [f_ticks] expand: f_ticks.%{%{reply:Packet-Type}:-format} -> f_ticks.Access-Accept [f_ticks] expand: F-TICKS/eduroam/1.0#REALM=%{Realm}#VISCOUNTRY=PT#VISINST=ISCTE#CSI=%{Calling-Station-Id}#RESULT=OK# -> F-TICKS/eduroam/1.0#REALM=DEFAULT#VISCOUNTRY=PT#VISINST=ISCTE#CSI=02-00-00-00-00-01#RESULT=OK# ++[f_ticks] returns ok ++[exec] returns noop Sending Access-Accept of id 8 to 10.10.32.35 port 54698 EAP-Message = 0x03080004 Message-Authenticator = 0x00000000000000000000000000000000 MS-MPPE-Send-Key = 0x9f48986d9d7e83edf67644bb52eebef557ac5978ae225052f6ef4abb7c5ca887 MS-MPPE-Recv-Key = 0xdb3285e803da7a0cbc29978eebf74ba8d2e66fafb2ba794e26916ea02f288a9a Finished request 8. Going to the next request Waking up in 4.4 seconds. Cleaning up request 0 ID 0 with timestamp +2 Cleaning up request 1 ID 1 with timestamp +2 Cleaning up request 2 ID 2 with timestamp +2 Waking up in 0.1 seconds. Cleaning up request 3 ID 3 with timestamp +2 Cleaning up request 4 ID 4 with timestamp +3 Cleaning up request 5 ID 5 with timestamp +3 Cleaning up request 6 ID 6 with timestamp +3 Cleaning up request 7 ID 7 with timestamp +3 Cleaning up request 8 ID 8 with timestamp +3 Ready to process requests. ^C radius2:/opt/bin/eduroam#