EAP-FAST phase2 failed
Ammu Argh
ammu3634 at gmail.com
Wed Sep 17 17:33:49 CEST 2014
Hi stephan,
As you suggested i tried to connect freeradous to active directory.
Freeradius is able to join the active directory and below command also
succeeded.
radtest -t mschap <user> <password> localhost 0 <sharedsecret>
But station failed to connect to AP.
I got the below error on freeradius:
EAP-FAST: Add EAP-Payload TLV
EAP-FAST: Encrypting Phase 2 TLVs - hexdump(len=9): [REMOVED]
EAP-FAST: Piggyback Phase 2 data (len=74) with last Phase 1 Message (len=59
used=0)
SSL: Generating Request
SSL: Sending out 133 bytes (message sent completely)
EAP: EAP entering state SEND_REQUEST
EAP: EAP entering state IDLE
EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
Wed Sep 17 12:06:41 2014 : Debug: ==> Request
Wed Sep 17 12:06:41 2014 : Info: ++[eap2] = handled
Wed Sep 17 12:06:41 2014 : Info: +} # group EAP = handled
Sending Access-Challenge of id 0 to 10.10.2.21 port 32769
EAP-Message =
0x0103008b2b011403010001011603010030ecbaeb0cb34edb4b5a2ba664ee29b3bc10415f193eea62b87aec7010764b27c9214f353e257ba45d088db01395af31921703010020553bf7bacca0e0deaaab76ced600289fa3cfd5e554f12194366f6daebb9457461703010020bfa25876dc10a3be2823cc57da70dacc00ba36be10cac7d3fab63abc9568da76
State = 0x168e1d8b4946cac447e29a10af5f74ab
Message-Authenticator = 0x00000000000000000000000000000000
Wed Sep 17 12:06:41 2014 : Info: Finished request 2.
Wed Sep 17 12:06:41 2014 : Debug: Going to the next request
Wed Sep 17 12:06:41 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.10.2.21 port 32769, id=0,
length=198
Wed Sep 17 12:06:41 2014 : Info: Cleaning up request 2 ID 0 with timestamp
+4
User-Name = "Administrator"
NAS-IP-Address = 10.10.2.21
Called-Station-Id = "00904c0dc3c0"
Calling-Station-Id = "b0df3a213196"
NAS-Identifier = "00904c0dc3c0"
NAS-Port = 6
Framed-MTU = 1400
State = 0x168e1d8b4946cac447e29a10af5f74ab
NAS-Port-Type = Wireless-802.11
EAP-Message =
0x0203003b2b01170301003095d9ea11cd8534ccc15833857d3abf3d4cde7bcfd6452e90a6376d38a1fbca5cd8866df13873ced31bcddb01b763a05a
Message-Authenticator = 0x8436f303447ef2fb778d130a29cde1fe
Wed Sep 17 12:06:41 2014 : Info: # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group authorize {
Wed Sep 17 12:06:41 2014 : Info: ++[preprocess] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[chap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[mschap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[digest] = noop
Wed Sep 17 12:06:41 2014 : Info: [suffix] No '@' in User-Name =
"Administrator", looking up realm NULL
Wed Sep 17 12:06:41 2014 : Info: [suffix] No such realm "NULL"
Wed Sep 17 12:06:41 2014 : Info: ++[suffix] = noop
Wed Sep 17 12:06:41 2014 : Info: [eap] EAP packet type response id 3 length
59
Wed Sep 17 12:06:41 2014 : Info: [eap] No EAP Start, assuming it's an
on-going EAP conversation
Wed Sep 17 12:06:41 2014 : Info: ++[eap] = updated
Wed Sep 17 12:06:41 2014 : Info: [files] users: Matched entry DEFAULT at
line 1
Wed Sep 17 12:06:41 2014 : Info: ++[files] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[expiration] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[logintime] = noop
Wed Sep 17 12:06:41 2014 : Info: [pap] WARNING! No "known good" password
found for the user. Authentication may fail because of this.
Wed Sep 17 12:06:41 2014 : Info: ++[pap] = noop
Wed Sep 17 12:06:41 2014 : Info: +} # group authorize = updated
Wed Sep 17 12:06:41 2014 : Info: Found Auth-Type = EAP
Wed Sep 17 12:06:41 2014 : Info: # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group EAP {
Wed Sep 17 12:06:41 2014 : Info: [eap2] Request found, released from the
list
EAP: EAP entering state RECEIVED
EAP: parseEapResp: rxResp=1 respId=3 respMethod=43 respVendor=0
respVendorMethod=0
EAP: EAP entering state INTEGRITY_CHECK
EAP: EAP entering state METHOD_RESPONSE
SSL: Received packet(len=59) - Flags 0x01
SSL: Received packet: Flags 0x1 Message Length 0
EAP-FAST: Received 53 bytes encrypted data for Phase 2
EAP-FAST: Decrypted Phase 2 TLVs - hexdump(len=22): [REMOVED]
EAP-FAST: Received Phase 2: TLV type 9 length 18 (mandatory)
EAP-FAST: EAP-Payload TLV - hexdump(len=18): 02 03 00 12 01 41 64 6d 69 6e
69 73 74 72 61 74 6f 72
EAP-FAST: Received Phase 2: code=2 identifier=3 length=18
EAP-Identity: Peer identity - hexdump_ascii(len=13):
41 64 6d 69 6e 69 73 74 72 61 74 6f 72 Administrator
EAP-FAST: PHASE2_ID -> PHASE2_METHOD
EAP-FAST: try EAP type 26
EAP: EAP entering state METHOD_REQUEST
EAP: building EAP-Request: Identifier 4
EAP-MSCHAPV2: Challenge - hexdump(len=16): 3f 59 4c c5 b1 d1 bc 71 62 df c1
49 70 6a 03 b7
EAP-FAST: Phase 2 EAP-Request - hexdump(len=33): [REMOVED]
EAP-FAST: Add EAP-Payload TLV
EAP-FAST: Encrypting Phase 2 TLVs - hexdump(len=37): [REMOVED]
SSL: Generating Request
SSL: Sending out 106 bytes (message sent completely)
EAP: EAP entering state SEND_REQUEST
EAP: EAP entering state IDLE
EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
Wed Sep 17 12:06:41 2014 : Debug: ==> Request
Wed Sep 17 12:06:41 2014 : Info: ++[eap2] = handled
Wed Sep 17 12:06:41 2014 : Info: +} # group EAP = handled
Sending Access-Challenge of id 0 to 10.10.2.21 port 32769
EAP-Message =
0x010400702b011703010020e4317e67f52197b376755f279b5e6623bba4be4333673a365d6162ddb21e5ba8170301004034291c01a1da6602565ad1e7ed03b4dd5f7a0f12d7f081fbd12e2fffdb304e1c5294279384159b5c2d8d003b3ef0dbfb15cf87af4db208b7259979816ada26c3
State = 0x9dd8b50daabbda5628fd760dd6fc5d4c
Message-Authenticator = 0x00000000000000000000000000000000
Wed Sep 17 12:06:41 2014 : Info: Finished request 3.
Wed Sep 17 12:06:41 2014 : Debug: Going to the next request
Wed Sep 17 12:06:41 2014 : Debug: Waking up in 4.9 seconds.
Wed Sep 17 12:06:46 2014 : Info: Cleaning up request 3 ID 0 with timestamp
+4
Wed Sep 17 12:06:46 2014 : Info: Ready to process requests.
Please find the attached complete console log for freeradius.
Please help me to make it work.
Regards
Ammu
On Fri, Aug 8, 2014 at 3:30 PM, <
freeradius-devel-request at lists.freeradius.org> wrote:
> Send Freeradius-Devel mailing list submissions to
> freeradius-devel at lists.freeradius.org
>
> To subscribe or unsubscribe via the World Wide Web, visit
> http://lists.freeradius.org/mailman/listinfo/freeradius-devel
> or, via email, send a message with subject or body 'help' to
> freeradius-devel-request at lists.freeradius.org
>
> You can reach the person managing the list at
> freeradius-devel-owner at lists.freeradius.org
>
> When replying, please edit your Subject line so it is more specific
> than "Re: Contents of Freeradius-Devel digest..."
>
>
> Today's Topics:
>
> 1. RE: EAP-FAST phase2 failed (Stefan Paetow)
>
>
> ----------------------------------------------------------------------
>
> Message: 1
> Date: Thu, 7 Aug 2014 21:25:46 +0000
> From: Stefan Paetow <Stefan.Paetow at ja.net>
> To: FreeRadius developers mailing list
> <freeradius-devel at lists.freeradius.org>
> Subject: RE: EAP-FAST phase2 failed
> Message-ID: <C072996E0B81144DBB9426B44462540C0D6935BF at EXC001>
> Content-Type: text/plain; charset="iso-8859-1"
>
> The log says this:
>
> EAP-MSCHAPV2: eap_server Password not configured
> EAP-FAST: Phase2 method failed
> EAP-FAST: PHASE2_METHOD -> FAILURE
>
> Leads me to believe you either need to configure EAP-FAST to use EAP-GTC
> or PAP as the second phase, or connect FR to SAMBA or Active Directory
> (which both speak MSCHAPv2).
>
> Stefan
>
> ________________________________
> From: freeradius-devel-bounces+stefan.paetow=ja.net at lists.freeradius.org
> [freeradius-devel-bounces+stefan.paetow=ja.net at lists.freeradius.org] on
> behalf of Ammu Argh [ammu3634 at gmail.com]
> Sent: 07 August 2014 17:16
> To: freeradius-devel at lists.freeradius.org
> Subject: EAP-FAST phase2 failed
>
> Hi,
>
> I was trying to connect to AP using EAP-FAST authentication.
> But Freeradius EAP-FAST failed with below error:
>
> State = 0x97d5bb340dc1cb0c525e6b44738f3553
> Message-Authenticator = 0xdce2fb540845c5ee76a5f48b505bb4eb
> # Executing section authorize from file
> /usr/local/etc/raddb/sites-enabled/default
> +group authorize {
> ++[preprocess] = ok
> ++[chap] = noop
> ++[mschap] = noop
> ++[digest] = noop
> [suffix] No '@' in User-Name = "anonymous", looking up realm NULL
> [suffix] No such realm "NULL"
> ++[suffix] = noop
> [eap] EAP packet type response id 4 length 107
> [eap] No EAP Start, assuming it's an on-going EAP conversation
> ++[eap] = updated
> [files] users: Matched entry DEFAULT at line 202
> ++[files] = ok
> ++[expiration] = noop
> ++[logintime] = noop
> [pap] WARNING! No "known good" password found for the user.
> Authentication may fail because of this.
> ++[pap] = noop
> +} # group authorize = updated
> Found Auth-Type = EAP
> # Executing group from file /usr/local/etc/raddb/sites-enabled/default
> +group EAP {
> [eap2] Request found, released from the list
> EAP: EAP entering state RECEIVED
> EAP: parseEapResp: rxResp=1 respId=4 respMethod=43 respVendor=0
> respVendorMethod=0
> EAP: EAP entering state INTEGRITY_CHECK
> EAP: EAP entering state METHOD_RESPONSE
> SSL: Received packet(len=107) - Flags 0x01
> SSL: Received packet: Flags 0x1 Message Length 0
> EAP-FAST: Received 101 bytes encrypted data for Phase 2
> EAP-FAST: Decrypted Phase 2 TLVs - hexdump(len=67): [REMOVED]
> EAP-FAST: Received Phase 2: TLV type 9 length 63 (mandatory)
> EAP-FAST: EAP-Payload TLV - hexdump(len=63): 02 04 00 3f 1a 02 04 00 3a 31
> 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 28
> 67 a5 fd 37 80 a6 91 10 ed 46 97 b2 70 75 aa cc 57 27 17 4e dc 0c 6c 00 77
> 69 66 69
> EAP-FAST: Received Phase 2: code=2 identifier=4 length=63
> EAP-MSCHAPV2: eap_server Password not configured
> EAP-FAST: Phase2 method failed
> EAP-FAST: PHASE2_METHOD -> FAILURE
> EAP: EAP entering state SELECT_ACTION
> EAP: getDecision: method failed -> FAILURE
> EAP: EAP entering state FAILURE
> EAP: Building EAP-Failure (id=4)
> ==> Fail
> [eap2] Freeing handler
> EAP: Server state machine removed
> ++[eap2] = reject
> +} # group EAP = reject
> Failed to authenticate the user.
> Using Post-Auth-Type REJECT
> # Executing group from file /usr/local/etc/raddb/sites-enabled/default
> +group REJECT {
> [attr_filter.access_reject] expand: %{User-Name} -> anonymous
> attr_filter: Matched entry DEFAULT at line 11
> ++[attr_filter.access_reject] = updated
> +} # group REJECT = updated
> Delaying reject of request 4 for 1 seconds
> Going to the next request
> Waking up in 0.9 seconds.
> Sending delayed reject for request 4
> Sending Access-Reject of id 117 to 10.10.2.2 port 46531
> EAP-Message = 0x04040004
> Message-Authenticator = 0x00000000000000000000000000000000
> Waking up in 3.9 seconds.
>
>
> Other details are as below"
>
> Users file"
> wifi Auth-Type := EAP, Cleartext-Password := "welcome123"
>
> eap.conf
> eap2 {
> fast {
> pac_opaque_encr_key =
> 000102030405060708090a0b0c0d0e0f
> eap_fast_a_id = tjsys
> eap_fast_a_id_info = my_server
> eap_fast_prov = 3
> pac_key_lifetime = 604800 # 7 days
> pac_key_refresh_tim = 86400
> }
>
> tls {
> ca_cert = /usr/local/etc/raddb/certs/ca.pem
> server_cert = /usr/local/etc/raddb/certs/server.pem
> private_key_file =
> /usr/local/etc/raddb/certs/server.key
> private_key_password = whatever
> dh_file = /usr/local/etc/raddb/certs/dh
> random_file = /usr/local/etc/raddb/certs/random
> }
> }
>
>
> Sites-enabled/default:
> Added in authenticate block
> Auth-Type EAP {
> eap2
> }
>
>
>
> wpa_supplicant.conf
> update_config=1
> ap_scan=1
> fast_reauth=1
>
> network={
> ssid="WiFi-11g"
> key_mgmt=WPA-EAP
> proto=WPA
> pairwise=TKIP
> group=TKIP
> eap=FAST
> anonymous_identity="fast"
> identity="fast"
> password="koro"
> phase1="fast_provisioning=3"
> pac_file="/data/misc/wifi/eap_fast.pac"
> }
>
>
>
> FreeRADIUS Version 2.2.5,
> OpenSSL 1.0.1e 11
> Ubuntu 14.04.1
>
> Please help me to get it work.
>
> Regards
> Ammu
>
> Janet(UK) is a trading name of Jisc Collections and Janet Limited, a
> not-for-profit company which is registered in England under No. 2881024
> and whose Registered Office is at Lumen House, Library Avenue,
> Harwell Oxford, Didcot, Oxfordshire. OX11 0SG. VAT No. 614944238
>
>
>
> ------------------------------
>
> -
> List info/subscribe/unsubscribe? See
> http://www.freeradius.org/list/devel.html
>
>
> End of Freeradius-Devel Digest, Vol 112, Issue 6
> ************************************************
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-devel/attachments/20140917/e2b11b84/attachment-0001.html>
-------------- next part --------------
Wed Sep 17 12:06:37 2014 : Info: radiusd: FreeRADIUS Version 2.2.5, for host x86_64-unknown-linux-gnu, built on Sep 15 2014 at 13:10:19
Wed Sep 17 12:06:37 2014 : Debug: Server was built with:
Wed Sep 17 12:06:37 2014 : Debug: accounting
Wed Sep 17 12:06:37 2014 : Debug: authentication
Wed Sep 17 12:06:37 2014 : Debug: WITH_DHCP
Wed Sep 17 12:06:37 2014 : Debug: WITH_VMPS
Wed Sep 17 12:06:37 2014 : Debug: Server core libs:
Wed Sep 17 12:06:37 2014 : Debug: ssl: OpenSSL 1.0.1f 6 Jan 2014
Wed Sep 17 12:06:37 2014 : Info: Copyright (C) 1999-2013 The FreeRADIUS server project and contributors.
Wed Sep 17 12:06:37 2014 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Wed Sep 17 12:06:37 2014 : Info: PARTICULAR PURPOSE.
Wed Sep 17 12:06:37 2014 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Wed Sep 17 12:06:37 2014 : Info: GNU General Public License.
Wed Sep 17 12:06:37 2014 : Info: For more information about these matters, see the file named COPYRIGHT.
Wed Sep 17 12:06:37 2014 : Info: Starting - reading configuration files ...
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/radiusd.conf
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/proxy.conf
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/clients.conf
Wed Sep 17 12:06:37 2014 : Debug: including files in directory /usr/local/etc/raddb/modules/
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.example.com
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/checkval
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/echo
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/pap
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/cui
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/krb5
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/smbpasswd
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/realm
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/sradutmp
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/linelog
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.log
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/pam
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_filter
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/otp
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/radutmp
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/ippool
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/logintime
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/inner-eap
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/detail
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2vlan
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/sql_log
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/perl
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/unix
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/wimax
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/ldap
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/dhcp_sqlippool
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/sql/mysql/ippool-dhcp.conf
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/rediswho
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/dynamic_clients
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/digest
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/chap
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/expiration
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/files
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/mschap
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/passwd
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/policy
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/smsotp
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/preprocess
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/always
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2ip
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/expr
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/exec
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_rewrite
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/ntlm_auth
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/replicate
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/redis
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/radrelay
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/soh
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/opendirectory
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/counter
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/cache
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/acct_unique
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/modules/etc_group
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/eap.conf
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/policy.conf
Wed Sep 17 12:06:37 2014 : Debug: including files in directory /usr/local/etc/raddb/sites-enabled/
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/control-socket
Wed Sep 17 12:06:37 2014 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:37 2014 : Debug: main {
Wed Sep 17 12:06:37 2014 : Debug: allow_core_dumps = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: including dictionary file /usr/local/etc/raddb/dictionary
Wed Sep 17 12:06:37 2014 : Debug: main {
Wed Sep 17 12:06:37 2014 : Debug: name = "radiusd"
Wed Sep 17 12:06:37 2014 : Debug: prefix = "/usr/local"
Wed Sep 17 12:06:37 2014 : Debug: localstatedir = "/usr/local/var"
Wed Sep 17 12:06:37 2014 : Debug: sbindir = "/usr/local/sbin"
Wed Sep 17 12:06:37 2014 : Debug: logdir = "/usr/local/var/log/radius"
Wed Sep 17 12:06:37 2014 : Debug: run_dir = "/usr/local/var/run/radiusd"
Wed Sep 17 12:06:37 2014 : Debug: libdir = "/usr/local/lib"
Wed Sep 17 12:06:37 2014 : Debug: radacctdir = "/usr/local/var/log/radius/radacct"
Wed Sep 17 12:06:37 2014 : Debug: hostname_lookups = no
Wed Sep 17 12:06:37 2014 : Debug: max_request_time = 30
Wed Sep 17 12:06:37 2014 : Debug: cleanup_delay = 5
Wed Sep 17 12:06:37 2014 : Debug: max_requests = 1024
Wed Sep 17 12:06:37 2014 : Debug: pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
Wed Sep 17 12:06:37 2014 : Debug: checkrad = "/usr/local/sbin/checkrad"
Wed Sep 17 12:06:37 2014 : Debug: debug_level = 0
Wed Sep 17 12:06:37 2014 : Debug: proxy_requests = yes
Wed Sep 17 12:06:37 2014 : Debug: log {
Wed Sep 17 12:06:37 2014 : Debug: stripped_names = no
Wed Sep 17 12:06:37 2014 : Debug: auth = no
Wed Sep 17 12:06:37 2014 : Debug: auth_badpass = no
Wed Sep 17 12:06:37 2014 : Debug: auth_goodpass = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: security {
Wed Sep 17 12:06:37 2014 : Debug: max_attributes = 200
Wed Sep 17 12:06:37 2014 : Debug: reject_delay = 1
Wed Sep 17 12:06:37 2014 : Debug: status_server = yes
Wed Sep 17 12:06:37 2014 : Debug: allow_vulnerable_openssl = yes
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: radiusd: #### Loading Realms and Home Servers ####
Wed Sep 17 12:06:37 2014 : Debug: proxy server {
Wed Sep 17 12:06:37 2014 : Debug: retry_delay = 5
Wed Sep 17 12:06:37 2014 : Debug: retry_count = 3
Wed Sep 17 12:06:37 2014 : Debug: default_fallback = no
Wed Sep 17 12:06:37 2014 : Debug: dead_time = 120
Wed Sep 17 12:06:37 2014 : Debug: wake_all_if_all_dead = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: home_server localhost {
Wed Sep 17 12:06:37 2014 : Debug: ipaddr = 127.0.0.1
Wed Sep 17 12:06:37 2014 : Debug: port = 1812
Wed Sep 17 12:06:37 2014 : Debug: type = "auth"
Wed Sep 17 12:06:37 2014 : Debug: secret = "testing123"
Wed Sep 17 12:06:37 2014 : Debug: response_window = 20
Wed Sep 17 12:06:37 2014 : Debug: max_outstanding = 65536
Wed Sep 17 12:06:37 2014 : Debug: require_message_authenticator = yes
Wed Sep 17 12:06:37 2014 : Debug: zombie_period = 40
Wed Sep 17 12:06:37 2014 : Debug: status_check = "status-server"
Wed Sep 17 12:06:37 2014 : Debug: ping_interval = 30
Wed Sep 17 12:06:37 2014 : Debug: check_interval = 30
Wed Sep 17 12:06:37 2014 : Debug: num_answers_to_alive = 3
Wed Sep 17 12:06:37 2014 : Debug: num_pings_to_alive = 3
Wed Sep 17 12:06:37 2014 : Debug: revive_interval = 120
Wed Sep 17 12:06:37 2014 : Debug: status_check_timeout = 4
Wed Sep 17 12:06:37 2014 : Debug: coa {
Wed Sep 17 12:06:37 2014 : Debug: irt = 2
Wed Sep 17 12:06:37 2014 : Debug: mrt = 16
Wed Sep 17 12:06:37 2014 : Debug: mrc = 5
Wed Sep 17 12:06:37 2014 : Debug: mrd = 30
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: home_server_pool my_auth_failover {
Wed Sep 17 12:06:37 2014 : Debug: type = fail-over
Wed Sep 17 12:06:37 2014 : Debug: home_server = localhost
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: realm example.com {
Wed Sep 17 12:06:37 2014 : Debug: auth_pool = my_auth_failover
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: realm LOCAL {
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: radiusd: #### Loading Clients ####
Wed Sep 17 12:06:37 2014 : Debug: client localhost {
Wed Sep 17 12:06:37 2014 : Debug: ipaddr = 127.0.0.1
Wed Sep 17 12:06:37 2014 : Debug: require_message_authenticator = no
Wed Sep 17 12:06:37 2014 : Debug: secret = "testing123"
Wed Sep 17 12:06:37 2014 : Debug: nastype = "other"
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: client 10.10.2.21 {
Wed Sep 17 12:06:37 2014 : Debug: require_message_authenticator = no
Wed Sep 17 12:06:37 2014 : Debug: secret = "testing123"
Wed Sep 17 12:06:37 2014 : Debug: shortname = "planex"
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: radiusd: #### Instantiating modules ####
Wed Sep 17 12:06:37 2014 : Debug: instantiate {
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_exec, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_exec
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "exec" from file /usr/local/etc/raddb/modules/exec
Wed Sep 17 12:06:37 2014 : Debug: exec {
Wed Sep 17 12:06:37 2014 : Debug: wait = no
Wed Sep 17 12:06:37 2014 : Debug: input_pairs = "request"
Wed Sep 17 12:06:37 2014 : Debug: shell_escape = yes
Wed Sep 17 12:06:37 2014 : Debug: timeout = 10
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_expr, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_expr
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "expr" from file /usr/local/etc/raddb/modules/expr
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_expiration, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_expiration
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "expiration" from file /usr/local/etc/raddb/modules/expiration
Wed Sep 17 12:06:37 2014 : Debug: expiration {
Wed Sep 17 12:06:37 2014 : Debug: reply-message = "Password Has Expired "
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_logintime, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_logintime
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "logintime" from file /usr/local/etc/raddb/modules/logintime
Wed Sep 17 12:06:37 2014 : Debug: logintime {
Wed Sep 17 12:06:37 2014 : Debug: reply-message = "You are calling outside your allowed timespan "
Wed Sep 17 12:06:37 2014 : Debug: minimum-timeout = 60
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: radiusd: #### Loading Virtual Servers ####
Wed Sep 17 12:06:37 2014 : Debug: server { # from file ?��??
Wed Sep 17 12:06:37 2014 : Debug: modules {
Wed Sep 17 12:06:37 2014 : Debug: Module: Creating Auth-Type = NTLM
Wed Sep 17 12:06:37 2014 : Debug: Module: Creating Auth-Type = digest
Wed Sep 17 12:06:37 2014 : Debug: Module: Creating Post-Auth-Type = REJECT
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking authenticate {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "ntlm_auth" from file /usr/local/etc/raddb/modules/ntlm_auth
Wed Sep 17 12:06:37 2014 : Debug: exec ntlm_auth {
Wed Sep 17 12:06:37 2014 : Debug: wait = yes
Wed Sep 17 12:06:37 2014 : Debug: program = "/usr/bin/ntlm_auth --request-nt-key --username=%{mschap:User-Name:-None} --domain=%{%{mschap:NT-Domain}:-wifilabs.local} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}"
Wed Sep 17 12:06:37 2014 : Debug: input_pairs = "request"
Wed Sep 17 12:06:37 2014 : Debug: shell_escape = yes
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_pap, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_pap
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "pap" from file /usr/local/etc/raddb/modules/pap
Wed Sep 17 12:06:37 2014 : Debug: pap {
Wed Sep 17 12:06:37 2014 : Debug: encryption_scheme = "auto"
Wed Sep 17 12:06:37 2014 : Debug: auto_header = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_eap2, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_eap2
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "eap2" from file /usr/local/etc/raddb/eap.conf
Wed Sep 17 12:06:37 2014 : Debug: eap2 {
Wed Sep 17 12:06:37 2014 : Debug: timer_expire = 60
Wed Sep 17 12:06:37 2014 : Debug: cisco_accounting_username_bug = no
Wed Sep 17 12:06:37 2014 : Debug: backend_auth = yes
Wed Sep 17 12:06:37 2014 : Debug: tls {
Wed Sep 17 12:06:37 2014 : Debug: ca_cert = "/usr/local/etc/raddb/certs/ca.pem"
Wed Sep 17 12:06:37 2014 : Debug: server_cert = "/usr/local/etc/raddb/certs/server.pem"
Wed Sep 17 12:06:37 2014 : Debug: private_key_file = "/usr/local/etc/raddb/certs/server.key"
Wed Sep 17 12:06:37 2014 : Debug: private_key_password = "whatever"
Wed Sep 17 12:06:37 2014 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh"
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: fast {
Wed Sep 17 12:06:37 2014 : Debug: pac_opaque_encr_key = "000102030405060708090a0b0c0d0e0f"
Wed Sep 17 12:06:37 2014 : Debug: eap_fast_a_id = "tjsys"
Wed Sep 17 12:06:37 2014 : Debug: eap_fast_a_id_info = "my_server"
Wed Sep 17 12:06:37 2014 : Debug: eap_fast_prov = 3
Wed Sep 17 12:06:37 2014 : Debug: pac_key_lifetime = 604800
Wed Sep 17 12:06:37 2014 : Debug: pac_key_refresh_time = 86400
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_chap, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_chap
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "chap" from file /usr/local/etc/raddb/modules/chap
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_mschap, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_mschap
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "mschap" from file /usr/local/etc/raddb/modules/mschap
Wed Sep 17 12:06:37 2014 : Debug: mschap {
Wed Sep 17 12:06:37 2014 : Debug: use_mppe = yes
Wed Sep 17 12:06:37 2014 : Debug: require_encryption = no
Wed Sep 17 12:06:37 2014 : Debug: require_strong = no
Wed Sep 17 12:06:37 2014 : Debug: with_ntdomain_hack = yes
Wed Sep 17 12:06:37 2014 : Debug: ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --username=%{mschap:User-Name:-None} --domain=%{%{mschap:NT-Domain}:-wifilabs.local} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}"
Wed Sep 17 12:06:37 2014 : Debug: allow_retry = yes
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_digest, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_digest
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "digest" from file /usr/local/etc/raddb/modules/digest
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_unix, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_unix
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "unix" from file /usr/local/etc/raddb/modules/unix
Wed Sep 17 12:06:37 2014 : Debug: unix {
Wed Sep 17 12:06:37 2014 : Debug: radwtmp = "/usr/local/var/log/radius/radwtmp"
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_eap, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_eap
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "eap" from file /usr/local/etc/raddb/eap.conf
Wed Sep 17 12:06:37 2014 : Debug: eap {
Wed Sep 17 12:06:37 2014 : Debug: default_eap_type = "md5"
Wed Sep 17 12:06:37 2014 : Debug: timer_expire = 60
Wed Sep 17 12:06:37 2014 : Debug: ignore_unknown_eap_types = no
Wed Sep 17 12:06:37 2014 : Debug: cisco_accounting_username_bug = no
Wed Sep 17 12:06:37 2014 : Debug: max_sessions = 1024
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to sub-module rlm_eap_md5
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating eap-md5
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to sub-module rlm_eap_leap
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating eap-leap
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to sub-module rlm_eap_gtc
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating eap-gtc
Wed Sep 17 12:06:37 2014 : Debug: gtc {
Wed Sep 17 12:06:37 2014 : Debug: challenge = "Password: "
Wed Sep 17 12:06:37 2014 : Debug: auth_type = "PAP"
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to sub-module rlm_eap_tls
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating eap-tls
Wed Sep 17 12:06:37 2014 : Debug: tls {
Wed Sep 17 12:06:37 2014 : Debug: rsa_key_exchange = no
Wed Sep 17 12:06:37 2014 : Debug: dh_key_exchange = yes
Wed Sep 17 12:06:37 2014 : Debug: rsa_key_length = 512
Wed Sep 17 12:06:37 2014 : Debug: dh_key_length = 512
Wed Sep 17 12:06:37 2014 : Debug: verify_depth = 0
Wed Sep 17 12:06:37 2014 : Debug: CA_path = "/usr/local/etc/raddb/certs"
Wed Sep 17 12:06:37 2014 : Debug: pem_file_type = yes
Wed Sep 17 12:06:37 2014 : Debug: private_key_file = "/usr/local/etc/raddb/certs/server.pem"
Wed Sep 17 12:06:37 2014 : Debug: certificate_file = "/usr/local/etc/raddb/certs/server.pem"
Wed Sep 17 12:06:37 2014 : Debug: CA_file = "/usr/local/etc/raddb/certs/ca.pem"
Wed Sep 17 12:06:37 2014 : Debug: private_key_password = "whatever"
Wed Sep 17 12:06:37 2014 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh"
Wed Sep 17 12:06:37 2014 : Debug: fragment_size = 1024
Wed Sep 17 12:06:37 2014 : Debug: include_length = yes
Wed Sep 17 12:06:37 2014 : Debug: check_crl = no
Wed Sep 17 12:06:37 2014 : Debug: cipher_list = "DEFAULT"
Wed Sep 17 12:06:37 2014 : Debug: make_cert_command = "/usr/local/etc/raddb/certs/bootstrap"
Wed Sep 17 12:06:37 2014 : Debug: ecdh_curve = "prime256v1"
Wed Sep 17 12:06:37 2014 : Debug: cache {
Wed Sep 17 12:06:37 2014 : Debug: enable = no
Wed Sep 17 12:06:37 2014 : Debug: lifetime = 24
Wed Sep 17 12:06:37 2014 : Debug: max_entries = 255
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: verify {
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: ocsp {
Wed Sep 17 12:06:37 2014 : Debug: enable = no
Wed Sep 17 12:06:37 2014 : Debug: override_cert_url = yes
Wed Sep 17 12:06:37 2014 : Debug: url = "http://127.0.0.1/ocsp/"
Wed Sep 17 12:06:37 2014 : Debug: use_nonce = yes
Wed Sep 17 12:06:37 2014 : Debug: timeout = 0
Wed Sep 17 12:06:37 2014 : Debug: softfail = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to sub-module rlm_eap_ttls
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating eap-ttls
Wed Sep 17 12:06:37 2014 : Debug: ttls {
Wed Sep 17 12:06:37 2014 : Debug: default_eap_type = "md5"
Wed Sep 17 12:06:37 2014 : Debug: copy_request_to_tunnel = no
Wed Sep 17 12:06:37 2014 : Debug: use_tunneled_reply = no
Wed Sep 17 12:06:37 2014 : Debug: virtual_server = "inner-tunnel"
Wed Sep 17 12:06:37 2014 : Debug: include_length = yes
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to sub-module rlm_eap_peap
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating eap-peap
Wed Sep 17 12:06:37 2014 : Debug: peap {
Wed Sep 17 12:06:37 2014 : Debug: default_eap_type = "mschapv2"
Wed Sep 17 12:06:37 2014 : Debug: copy_request_to_tunnel = no
Wed Sep 17 12:06:37 2014 : Debug: use_tunneled_reply = no
Wed Sep 17 12:06:37 2014 : Debug: proxy_tunneled_request_as_eap = yes
Wed Sep 17 12:06:37 2014 : Debug: virtual_server = "inner-tunnel"
Wed Sep 17 12:06:37 2014 : Debug: soh = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to sub-module rlm_eap_mschapv2
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating eap-mschapv2
Wed Sep 17 12:06:37 2014 : Debug: mschapv2 {
Wed Sep 17 12:06:37 2014 : Debug: with_ntdomain_hack = no
Wed Sep 17 12:06:37 2014 : Debug: send_error = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking authorize {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_preprocess, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_preprocess
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "preprocess" from file /usr/local/etc/raddb/modules/preprocess
Wed Sep 17 12:06:37 2014 : Debug: preprocess {
Wed Sep 17 12:06:37 2014 : Debug: huntgroups = "/usr/local/etc/raddb/huntgroups"
Wed Sep 17 12:06:37 2014 : Debug: hints = "/usr/local/etc/raddb/hints"
Wed Sep 17 12:06:37 2014 : Debug: with_ascend_hack = no
Wed Sep 17 12:06:37 2014 : Debug: ascend_channels_per_line = 23
Wed Sep 17 12:06:37 2014 : Debug: with_ntdomain_hack = no
Wed Sep 17 12:06:37 2014 : Debug: with_specialix_jetstream_hack = no
Wed Sep 17 12:06:37 2014 : Debug: with_cisco_vsa_hack = no
Wed Sep 17 12:06:37 2014 : Debug: with_alvarion_vsa_hack = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: reading pairlist file /usr/local/etc/raddb/huntgroups
Wed Sep 17 12:06:37 2014 : Debug: reading pairlist file /usr/local/etc/raddb/hints
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_realm, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_realm
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "suffix" from file /usr/local/etc/raddb/modules/realm
Wed Sep 17 12:06:37 2014 : Debug: realm suffix {
Wed Sep 17 12:06:37 2014 : Debug: format = "suffix"
Wed Sep 17 12:06:37 2014 : Debug: delimiter = "@"
Wed Sep 17 12:06:37 2014 : Debug: ignore_default = no
Wed Sep 17 12:06:37 2014 : Debug: ignore_null = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_files, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_files
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "files" from file /usr/local/etc/raddb/modules/files
Wed Sep 17 12:06:37 2014 : Debug: files {
Wed Sep 17 12:06:37 2014 : Debug: usersfile = "/usr/local/etc/raddb/users"
Wed Sep 17 12:06:37 2014 : Debug: acctusersfile = "/usr/local/etc/raddb/acct_users"
Wed Sep 17 12:06:37 2014 : Debug: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
Wed Sep 17 12:06:37 2014 : Debug: compat = "no"
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: reading pairlist file /usr/local/etc/raddb/users
Wed Sep 17 12:06:37 2014 : Debug: reading pairlist file /usr/local/etc/raddb/acct_users
Wed Sep 17 12:06:37 2014 : Debug: reading pairlist file /usr/local/etc/raddb/preproxy_users
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking preacct {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_acct_unique, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_acct_unique
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "acct_unique" from file /usr/local/etc/raddb/modules/acct_unique
Wed Sep 17 12:06:37 2014 : Debug: acct_unique {
Wed Sep 17 12:06:37 2014 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port"
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking accounting {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_detail, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_detail
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "detail" from file /usr/local/etc/raddb/modules/detail
Wed Sep 17 12:06:37 2014 : Debug: detail {
Wed Sep 17 12:06:37 2014 : Debug: detailfile = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Wed Sep 17 12:06:37 2014 : Debug: header = "%t"
Wed Sep 17 12:06:37 2014 : Debug: detailperm = 384
Wed Sep 17 12:06:37 2014 : Debug: dirperm = 493
Wed Sep 17 12:06:37 2014 : Debug: locking = no
Wed Sep 17 12:06:37 2014 : Debug: log_packet_header = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_attr_filter, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_attr_filter
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/modules/attr_filter
Wed Sep 17 12:06:37 2014 : Debug: attr_filter attr_filter.accounting_response {
Wed Sep 17 12:06:37 2014 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"
Wed Sep 17 12:06:37 2014 : Debug: key = "%{User-Name}"
Wed Sep 17 12:06:37 2014 : Debug: relaxed = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: reading pairlist file /usr/local/etc/raddb/attrs.accounting_response
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking session {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: (Loaded rlm_radutmp, checking if it's valid)
Wed Sep 17 12:06:37 2014 : Debug: Module: Linked to module rlm_radutmp
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "radutmp" from file /usr/local/etc/raddb/modules/radutmp
Wed Sep 17 12:06:37 2014 : Debug: radutmp {
Wed Sep 17 12:06:37 2014 : Debug: filename = "/usr/local/var/log/radius/radutmp"
Wed Sep 17 12:06:37 2014 : Debug: username = "%{User-Name}"
Wed Sep 17 12:06:37 2014 : Debug: case_sensitive = yes
Wed Sep 17 12:06:37 2014 : Debug: check_with_nas = yes
Wed Sep 17 12:06:37 2014 : Debug: perm = 384
Wed Sep 17 12:06:37 2014 : Debug: callerid = yes
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking post-proxy {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking post-auth {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/modules/attr_filter
Wed Sep 17 12:06:37 2014 : Debug: attr_filter attr_filter.access_reject {
Wed Sep 17 12:06:37 2014 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.access_reject"
Wed Sep 17 12:06:37 2014 : Debug: key = "%{User-Name}"
Wed Sep 17 12:06:37 2014 : Debug: relaxed = no
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: reading pairlist file /usr/local/etc/raddb/attrs.access_reject
Wed Sep 17 12:06:37 2014 : Debug: } # modules
Wed Sep 17 12:06:37 2014 : Debug: } # server
Wed Sep 17 12:06:37 2014 : Debug: server inner-tunnel { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel
Wed Sep 17 12:06:37 2014 : Debug: modules {
Wed Sep 17 12:06:37 2014 : Debug: Module: Creating Auth-Type = ntlm_auth
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking authenticate {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking authorize {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking session {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking post-proxy {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: Module: Checking post-auth {...} for more modules to load
Wed Sep 17 12:06:37 2014 : Debug: } # modules
Wed Sep 17 12:06:37 2014 : Debug: } # server
Wed Sep 17 12:06:37 2014 : Debug: radiusd: #### Opening IP addresses and Ports ####
Wed Sep 17 12:06:37 2014 : Debug: listen {
Wed Sep 17 12:06:37 2014 : Debug: type = "auth"
Wed Sep 17 12:06:37 2014 : Debug: ipaddr = *
Wed Sep 17 12:06:37 2014 : Debug: port = 0
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: listen {
Wed Sep 17 12:06:37 2014 : Debug: type = "acct"
Wed Sep 17 12:06:37 2014 : Debug: ipaddr = *
Wed Sep 17 12:06:37 2014 : Debug: port = 0
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: listen {
Wed Sep 17 12:06:37 2014 : Debug: type = "control"
Wed Sep 17 12:06:37 2014 : Debug: listen {
Wed Sep 17 12:06:37 2014 : Debug: socket = "/usr/local/var/run/radiusd/radiusd.sock"
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: listen {
Wed Sep 17 12:06:37 2014 : Debug: type = "auth"
Wed Sep 17 12:06:37 2014 : Debug: ipaddr = 127.0.0.1
Wed Sep 17 12:06:37 2014 : Debug: port = 18120
Wed Sep 17 12:06:37 2014 : Debug: }
Wed Sep 17 12:06:37 2014 : Debug: ... adding new socket proxy address * port 57509
Wed Sep 17 12:06:37 2014 : Debug: Listening on authentication address * port 1812
Wed Sep 17 12:06:37 2014 : Debug: Listening on accounting address * port 1813
Wed Sep 17 12:06:37 2014 : Debug: Listening on command file /usr/local/var/run/radiusd/radiusd.sock
Wed Sep 17 12:06:37 2014 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Wed Sep 17 12:06:37 2014 : Debug: Listening on proxy address * port 1814
Wed Sep 17 12:06:37 2014 : Info: Ready to process requests.
TLS: Trusted root certificate(s) loaded
rad_recv: Access-Request packet from host 10.10.2.21 port 32769, id=0, length=139
User-Name = "Administrator"
NAS-IP-Address = 10.10.2.21
Called-Station-Id = "00904c0dc3c0"
Calling-Station-Id = "b0df3a213196"
NAS-Identifier = "00904c0dc3c0"
NAS-Port = 6
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020000120141646d696e6973747261746f72
Message-Authenticator = 0x6edc31d2d5c24e4ab9a7dc76563162f7
Wed Sep 17 12:06:41 2014 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group authorize {
Wed Sep 17 12:06:41 2014 : Info: ++[preprocess] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[chap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[mschap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[digest] = noop
Wed Sep 17 12:06:41 2014 : Info: [suffix] No '@' in User-Name = "Administrator", looking up realm NULL
Wed Sep 17 12:06:41 2014 : Info: [suffix] No such realm "NULL"
Wed Sep 17 12:06:41 2014 : Info: ++[suffix] = noop
Wed Sep 17 12:06:41 2014 : Info: [eap] EAP packet type response id 0 length 18
Wed Sep 17 12:06:41 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Sep 17 12:06:41 2014 : Info: ++[eap] = updated
Wed Sep 17 12:06:41 2014 : Info: [files] users: Matched entry DEFAULT at line 1
Wed Sep 17 12:06:41 2014 : Info: ++[files] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[expiration] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[logintime] = noop
Wed Sep 17 12:06:41 2014 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.
Wed Sep 17 12:06:41 2014 : Info: ++[pap] = noop
Wed Sep 17 12:06:41 2014 : Info: +} # group authorize = updated
Wed Sep 17 12:06:41 2014 : Info: Found Auth-Type = EAP
Wed Sep 17 12:06:41 2014 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group EAP {
EAP: Server state machine created
EAP: EAP entering state INITIALIZE
EAP: parseEapResp: rxResp=1 respId=0 respMethod=1 respVendor=0 respVendorMethod=0
EAP: EAP entering state PICK_UP_METHOD
EAP: EAP entering state METHOD_RESPONSE
EAP-Identity: Peer identity - hexdump_ascii(len=13):
41 64 6d 69 6e 69 73 74 72 61 74 6f 72 Administrator
EAP: EAP entering state SELECT_ACTION
EAP: getDecision: another method available -> CONTINUE
EAP: EAP entering state PROPOSE_METHOD
EAP: getNextMethod: vendor 0 type 43
OpenSSL: cipher suites: ADH-AES128-SHA:AES128-SHA:DHE-RSA-AES128-SHA:RC4-SHA
EAP: EAP entering state METHOD_REQUEST
EAP: building EAP-Request: Identifier 1
EAP-FAST: START -> PHASE1
EAP: EAP entering state SEND_REQUEST
EAP: EAP entering state IDLE
EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
Wed Sep 17 12:06:41 2014 : Debug: ==> Request
Wed Sep 17 12:06:41 2014 : Info: ++[eap2] = handled
Wed Sep 17 12:06:41 2014 : Info: +} # group EAP = handled
Sending Access-Challenge of id 0 to 10.10.2.21 port 32769
EAP-Message = 0x0101000f2b2100040005746a737973
State = 0x8bdc2a12eac6efe846833b075f18905a
Message-Authenticator = 0x00000000000000000000000000000000
Wed Sep 17 12:06:41 2014 : Info: Finished request 0.
Wed Sep 17 12:06:41 2014 : Debug: Going to the next request
Wed Sep 17 12:06:41 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.10.2.21 port 32769, id=0, length=203
Wed Sep 17 12:06:41 2014 : Info: Cleaning up request 0 ID 0 with timestamp +4
User-Name = "Administrator"
NAS-IP-Address = 10.10.2.21
Called-Station-Id = "00904c0dc3c0"
Calling-Station-Id = "b0df3a213196"
NAS-Identifier = "00904c0dc3c0"
NAS-Port = 6
Framed-MTU = 1400
State = 0x8bdc2a12eac6efe846833b075f18905a
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020100402b01160301003501000031030154192b942c524c11750e80d3d26b207024e3ba0b21d4da77927379103574dd3e00000a00340033002f000500ff0100
Message-Authenticator = 0xffe1e97ba8954dce435d6c3f66de7f37
Wed Sep 17 12:06:41 2014 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group authorize {
Wed Sep 17 12:06:41 2014 : Info: ++[preprocess] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[chap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[mschap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[digest] = noop
Wed Sep 17 12:06:41 2014 : Info: [suffix] No '@' in User-Name = "Administrator", looking up realm NULL
Wed Sep 17 12:06:41 2014 : Info: [suffix] No such realm "NULL"
Wed Sep 17 12:06:41 2014 : Info: ++[suffix] = noop
Wed Sep 17 12:06:41 2014 : Info: [eap] EAP packet type response id 1 length 64
Wed Sep 17 12:06:41 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Sep 17 12:06:41 2014 : Info: ++[eap] = updated
Wed Sep 17 12:06:41 2014 : Info: [files] users: Matched entry DEFAULT at line 1
Wed Sep 17 12:06:41 2014 : Info: ++[files] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[expiration] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[logintime] = noop
Wed Sep 17 12:06:41 2014 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.
Wed Sep 17 12:06:41 2014 : Info: ++[pap] = noop
Wed Sep 17 12:06:41 2014 : Info: +} # group authorize = updated
Wed Sep 17 12:06:41 2014 : Info: Found Auth-Type = EAP
Wed Sep 17 12:06:41 2014 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group EAP {
Wed Sep 17 12:06:41 2014 : Info: [eap2] Request found, released from the list
EAP: EAP entering state RECEIVED
EAP: parseEapResp: rxResp=1 respId=1 respMethod=43 respVendor=0 respVendorMethod=0
EAP: EAP entering state INTEGRITY_CHECK
EAP: EAP entering state METHOD_RESPONSE
SSL: Received packet(len=64) - Flags 0x01
SSL: Received packet: Flags 0x1 Message Length 0
SSL: (where=0x10 ret=0x1)
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:before/accept initialization
EAP-FAST: SessionTicket callback
EAP-FAST: SessionTicket (PAC-Opaque) - hexdump(len=0): [NULL]
EAP-FAST: Ignore invalid SessionTicket
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 read client hello A
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 write server hello A
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 write key exchange A
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 write server done A
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 flush data
SSL: (where=0x2002 ret=0xffffffff)
SSL: SSL_accept:error in SSLv3 read client certificate A
SSL: SSL_accept - want more data
SSL: 367 bytes pending from ssl_out
EAP: EAP entering state METHOD_REQUEST
EAP: building EAP-Request: Identifier 2
SSL: Generating Request
SSL: Sending out 367 bytes (message sent completely)
EAP: EAP entering state SEND_REQUEST
EAP: EAP entering state IDLE
EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
Wed Sep 17 12:06:41 2014 : Debug: ==> Request
Wed Sep 17 12:06:41 2014 : Info: ++[eap2] = handled
Wed Sep 17 12:06:41 2014 : Info: +} # group EAP = handled
Sending Access-Challenge of id 0 to 10.10.2.21 port 32769
EAP-Message = 0x010201752b0116030100510200004d03019bea264d0a4650688415a98c36647ae0f9c3f66858c63acbcf1cdf471d8ac2b120f54d966f7948bd6a2964f6b11c312e474715b576d1b02f8972e3026dccb9517c0034000005ff01000100160301010b0c0001070080de4cb0a195a152c976400f10682e0e44661c747fc84263fa95f672c948d6c9972c4acaf67af770a00b57c825dec1f8f8b775d9dca2aaded3290941987e97e6381323bdb6eba418782505fa13bee56124eca507db525932bf59d821ec6fd94fe0824914d623c8b5a309c1f9bfa6611efcc4531ce93adb2f904d1872b908ea5363000102008019de88e5894bbd3928507a3ca73948ff64
EAP-Message = 0xfd2effa7b3b790ddee8490d6110701c33756f9257aff9f1a9c9b62b8af10025b223ff81c0875c04efc6d60d85ce40ea3882efac87d57b73736f2193a32833bb48d506f768b23158f7cc1082eca82063f30eb36647c0de221c7df06ca2c6316d2312a5b1b38271eb49e44d1907365d616030100040e000000
State = 0x937a095447bfdff66f615e837da27188
Message-Authenticator = 0x00000000000000000000000000000000
Wed Sep 17 12:06:41 2014 : Info: Finished request 1.
Wed Sep 17 12:06:41 2014 : Debug: Going to the next request
Wed Sep 17 12:06:41 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.10.2.21 port 32769, id=0, length=343
Wed Sep 17 12:06:41 2014 : Info: Cleaning up request 1 ID 0 with timestamp +4
User-Name = "Administrator"
NAS-IP-Address = 10.10.2.21
Called-Station-Id = "00904c0dc3c0"
Calling-Station-Id = "b0df3a213196"
NAS-Identifier = "00904c0dc3c0"
NAS-Port = 6
Framed-MTU = 1400
State = 0x937a095447bfdff66f615e837da27188
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020200cc2b011603010086100000820080c780bed8e5ad3cce87bb388f5d65f11afd0c1347267b923688189e8fa5462eae76d0da07bcf1c540e82194fd2dc001c87fd27aaf2c3313dd0949e9d7bcc8c3893478b436d47ed726d19ccb81514aea9e9bf734d744ac44751821d212d53fa4bf6e9d9a76ef51a8da802bcb9006efa3e2820c296c668664c57527353fdd1db7431403010001011603010030e039dabde4949e8054bebb08b847852933c849f46075bce8930104da7240fb24bb506a040c8779f83215e6986f1baafc
Message-Authenticator = 0x512d573323cf40b027b25a6802a0c718
Wed Sep 17 12:06:41 2014 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group authorize {
Wed Sep 17 12:06:41 2014 : Info: ++[preprocess] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[chap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[mschap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[digest] = noop
Wed Sep 17 12:06:41 2014 : Info: [suffix] No '@' in User-Name = "Administrator", looking up realm NULL
Wed Sep 17 12:06:41 2014 : Info: [suffix] No such realm "NULL"
Wed Sep 17 12:06:41 2014 : Info: ++[suffix] = noop
Wed Sep 17 12:06:41 2014 : Info: [eap] EAP packet type response id 2 length 204
Wed Sep 17 12:06:41 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Sep 17 12:06:41 2014 : Info: ++[eap] = updated
Wed Sep 17 12:06:41 2014 : Info: [files] users: Matched entry DEFAULT at line 1
Wed Sep 17 12:06:41 2014 : Info: ++[files] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[expiration] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[logintime] = noop
Wed Sep 17 12:06:41 2014 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.
Wed Sep 17 12:06:41 2014 : Info: ++[pap] = noop
Wed Sep 17 12:06:41 2014 : Info: +} # group authorize = updated
Wed Sep 17 12:06:41 2014 : Info: Found Auth-Type = EAP
Wed Sep 17 12:06:41 2014 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group EAP {
Wed Sep 17 12:06:41 2014 : Info: [eap2] Request found, released from the list
EAP: EAP entering state RECEIVED
EAP: parseEapResp: rxResp=1 respId=2 respMethod=43 respVendor=0 respVendorMethod=0
EAP: EAP entering state INTEGRITY_CHECK
EAP: EAP entering state METHOD_RESPONSE
SSL: Received packet(len=204) - Flags 0x01
SSL: Received packet: Flags 0x1 Message Length 0
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 read client key exchange A
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 read finished A
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 write change cipher spec A
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 write finished A
SSL: (where=0x2001 ret=0x1)
SSL: SSL_accept:SSLv3 flush data
SSL: (where=0x20 ret=0x1)
SSL: (where=0x2002 ret=0x1)
SSL: 59 bytes pending from ssl_out
EAP: EAP entering state METHOD_REQUEST
EAP: building EAP-Request: Identifier 3
EAP-FAST: Phase1 done, starting Phase2
EAP-FAST: Anonymous provisioning
EAP-FAST: master_secret for key expansion - hexdump(len=48): [REMOVED]
EAP-FAST: session_key_seed (SKS = S-IMCK[0]) - hexdump(len=40): [REMOVED]
EAP-FAST: server_challenge - hexdump(len=16): [REMOVED]
EAP-FAST: client_challenge - hexdump(len=16): [REMOVED]
EAP-FAST: PHASE1 -> PHASE2_START
EAP-FAST: Try to start Phase 2
EAP-FAST: PHASE2_START -> PHASE2_ID
EAP-FAST: Phase 2 EAP-Request - hexdump(len=5): [REMOVED]
EAP-FAST: Add EAP-Payload TLV
EAP-FAST: Encrypting Phase 2 TLVs - hexdump(len=9): [REMOVED]
EAP-FAST: Piggyback Phase 2 data (len=74) with last Phase 1 Message (len=59 used=0)
SSL: Generating Request
SSL: Sending out 133 bytes (message sent completely)
EAP: EAP entering state SEND_REQUEST
EAP: EAP entering state IDLE
EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
Wed Sep 17 12:06:41 2014 : Debug: ==> Request
Wed Sep 17 12:06:41 2014 : Info: ++[eap2] = handled
Wed Sep 17 12:06:41 2014 : Info: +} # group EAP = handled
Sending Access-Challenge of id 0 to 10.10.2.21 port 32769
EAP-Message = 0x0103008b2b011403010001011603010030ecbaeb0cb34edb4b5a2ba664ee29b3bc10415f193eea62b87aec7010764b27c9214f353e257ba45d088db01395af31921703010020553bf7bacca0e0deaaab76ced600289fa3cfd5e554f12194366f6daebb9457461703010020bfa25876dc10a3be2823cc57da70dacc00ba36be10cac7d3fab63abc9568da76
State = 0x168e1d8b4946cac447e29a10af5f74ab
Message-Authenticator = 0x00000000000000000000000000000000
Wed Sep 17 12:06:41 2014 : Info: Finished request 2.
Wed Sep 17 12:06:41 2014 : Debug: Going to the next request
Wed Sep 17 12:06:41 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.10.2.21 port 32769, id=0, length=198
Wed Sep 17 12:06:41 2014 : Info: Cleaning up request 2 ID 0 with timestamp +4
User-Name = "Administrator"
NAS-IP-Address = 10.10.2.21
Called-Station-Id = "00904c0dc3c0"
Calling-Station-Id = "b0df3a213196"
NAS-Identifier = "00904c0dc3c0"
NAS-Port = 6
Framed-MTU = 1400
State = 0x168e1d8b4946cac447e29a10af5f74ab
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x0203003b2b01170301003095d9ea11cd8534ccc15833857d3abf3d4cde7bcfd6452e90a6376d38a1fbca5cd8866df13873ced31bcddb01b763a05a
Message-Authenticator = 0x8436f303447ef2fb778d130a29cde1fe
Wed Sep 17 12:06:41 2014 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group authorize {
Wed Sep 17 12:06:41 2014 : Info: ++[preprocess] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[chap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[mschap] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[digest] = noop
Wed Sep 17 12:06:41 2014 : Info: [suffix] No '@' in User-Name = "Administrator", looking up realm NULL
Wed Sep 17 12:06:41 2014 : Info: [suffix] No such realm "NULL"
Wed Sep 17 12:06:41 2014 : Info: ++[suffix] = noop
Wed Sep 17 12:06:41 2014 : Info: [eap] EAP packet type response id 3 length 59
Wed Sep 17 12:06:41 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Sep 17 12:06:41 2014 : Info: ++[eap] = updated
Wed Sep 17 12:06:41 2014 : Info: [files] users: Matched entry DEFAULT at line 1
Wed Sep 17 12:06:41 2014 : Info: ++[files] = ok
Wed Sep 17 12:06:41 2014 : Info: ++[expiration] = noop
Wed Sep 17 12:06:41 2014 : Info: ++[logintime] = noop
Wed Sep 17 12:06:41 2014 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.
Wed Sep 17 12:06:41 2014 : Info: ++[pap] = noop
Wed Sep 17 12:06:41 2014 : Info: +} # group authorize = updated
Wed Sep 17 12:06:41 2014 : Info: Found Auth-Type = EAP
Wed Sep 17 12:06:41 2014 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default
Wed Sep 17 12:06:41 2014 : Info: +group EAP {
Wed Sep 17 12:06:41 2014 : Info: [eap2] Request found, released from the list
EAP: EAP entering state RECEIVED
EAP: parseEapResp: rxResp=1 respId=3 respMethod=43 respVendor=0 respVendorMethod=0
EAP: EAP entering state INTEGRITY_CHECK
EAP: EAP entering state METHOD_RESPONSE
SSL: Received packet(len=59) - Flags 0x01
SSL: Received packet: Flags 0x1 Message Length 0
EAP-FAST: Received 53 bytes encrypted data for Phase 2
EAP-FAST: Decrypted Phase 2 TLVs - hexdump(len=22): [REMOVED]
EAP-FAST: Received Phase 2: TLV type 9 length 18 (mandatory)
EAP-FAST: EAP-Payload TLV - hexdump(len=18): 02 03 00 12 01 41 64 6d 69 6e 69 73 74 72 61 74 6f 72
EAP-FAST: Received Phase 2: code=2 identifier=3 length=18
EAP-Identity: Peer identity - hexdump_ascii(len=13):
41 64 6d 69 6e 69 73 74 72 61 74 6f 72 Administrator
EAP-FAST: PHASE2_ID -> PHASE2_METHOD
EAP-FAST: try EAP type 26
EAP: EAP entering state METHOD_REQUEST
EAP: building EAP-Request: Identifier 4
EAP-MSCHAPV2: Challenge - hexdump(len=16): 3f 59 4c c5 b1 d1 bc 71 62 df c1 49 70 6a 03 b7
EAP-FAST: Phase 2 EAP-Request - hexdump(len=33): [REMOVED]
EAP-FAST: Add EAP-Payload TLV
EAP-FAST: Encrypting Phase 2 TLVs - hexdump(len=37): [REMOVED]
SSL: Generating Request
SSL: Sending out 106 bytes (message sent completely)
EAP: EAP entering state SEND_REQUEST
EAP: EAP entering state IDLE
EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
Wed Sep 17 12:06:41 2014 : Debug: ==> Request
Wed Sep 17 12:06:41 2014 : Info: ++[eap2] = handled
Wed Sep 17 12:06:41 2014 : Info: +} # group EAP = handled
Sending Access-Challenge of id 0 to 10.10.2.21 port 32769
EAP-Message = 0x010400702b011703010020e4317e67f52197b376755f279b5e6623bba4be4333673a365d6162ddb21e5ba8170301004034291c01a1da6602565ad1e7ed03b4dd5f7a0f12d7f081fbd12e2fffdb304e1c5294279384159b5c2d8d003b3ef0dbfb15cf87af4db208b7259979816ada26c3
State = 0x9dd8b50daabbda5628fd760dd6fc5d4c
Message-Authenticator = 0x00000000000000000000000000000000
Wed Sep 17 12:06:41 2014 : Info: Finished request 3.
Wed Sep 17 12:06:41 2014 : Debug: Going to the next request
Wed Sep 17 12:06:41 2014 : Debug: Waking up in 4.9 seconds.
Wed Sep 17 12:06:46 2014 : Info: Cleaning up request 3 ID 0 with timestamp +4
Wed Sep 17 12:06:46 2014 : Info: Ready to process requests.
More information about the Freeradius-Devel
mailing list