Hi Louis,
Thanks, it is a bit long. I replaced the domain name with domain, and replaced
the username with my_ad_user.
Wed Apr 27 15:09:36 2016 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.1.10.234 port 33734, id=188,
length=220
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8C-70-5A-05-81-7C"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84-18-3A-3A-12-AC:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
EAP-Message = 0x02020017015155414c59534f46545c676261726f637369
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Message-Authenticator = 0x0096266da4af2bfdbbf5c8b92cdf61ef
Wed Apr 27 15:09:44 2016 : Info: server packetfence {
Wed Apr 27 15:09:44 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:44 2016 : Info: +group authorize {
Wed Apr 27 15:09:44 2016 : Info: ++policy rewrite.calling_station_id {
Wed Apr 27 15:09:44 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Wed Apr 27 15:09:44 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: expand: %{Calling-Station-Id} ->
8C-70-5A-05-81-7C
Wed Apr 27 15:09:44 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:44 2016 : Info: expand: ^%{config:policy.mac-addr}$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([-f]?([0-9a-f]{2})$
Wed Apr 27 15:09:44 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~
/^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: +++if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Wed Apr 27 15:09:44 2016 : Info: ++++update request {
Wed Apr 27 15:09:44 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 8C:70:5A:05:81:7C
Wed Apr 27 15:09:44 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 8c:70:5a:05:81:7c
Wed Apr 27 15:09:44 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:44 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:44 2016 : Info: +++} # if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Wed Apr 27 15:09:44 2016 : Info: +++ ... skipping else for request 0: Preceding
"if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++} # policy rewrite.calling_station_id =
updated
Wed Apr 27 15:09:44 2016 : Info: ++policy set.called_station_ssid {
Wed Apr 27 15:09:44 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i)
Wed Apr 27 15:09:44 2016 : Info: ?? Evaluating (Called-Station-Id) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: expand: %{Called-Station-Id} ->
84-18-3A-3A-12-AC:Packetfence
Wed Apr 27 15:09:44 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:44 2016 : Info: expand:
^%{config:policy.mac-addr}(:(.+))?$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$
Wed Apr 27 15:09:44 2016 : Info: ? Evaluating ("%{Called-Station-Id}" =~
/^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: +++if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) {
Wed Apr 27 15:09:44 2016 : Info: ++++update request {
Wed Apr 27 15:09:44 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 84:18:3A:3A:12:AC
Wed Apr 27 15:09:44 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 84:18:3a:3a:12:ac
Wed Apr 27 15:09:44 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:44 2016 : Info: ++++? if ("%{8}")
Wed Apr 27 15:09:44 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:44 2016 : Info: ? Evaluating ("%{8}") -> TRUE
Wed Apr 27 15:09:44 2016 : Info: ++++? if ("%{8}") -> TRUE
Wed Apr 27 15:09:44 2016 : Info: ++++if ("%{8}") {
Wed Apr 27 15:09:44 2016 : Info: +++++update request {
Wed Apr 27 15:09:44 2016 : Info: expand: %{Called-Station-Id}:%{8} ->
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:44 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:44 2016 : Info: +++++} # update request = noop
Wed Apr 27 15:09:44 2016 : Info: ++++} # if ("%{8}") = noop
Wed Apr 27 15:09:44 2016 : Info: ++++ ... skipping elsif for request 0:
Preceding "if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++++ ... skipping elsif for request 0:
Preceding "if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++++ ... skipping elsif for request 0:
Preceding "if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:44 2016 : Info: +++} # if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) = updated
Wed Apr 27 15:09:44 2016 : Info: +++ ... skipping else for request 0: Preceding
"if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++} # policy set.called_station_ssid = updated
Wed Apr 27 15:09:44 2016 : Info: [suffix] No '@' in User-Name =
"domain\my_ad_user", skipping NULL due to config.
Wed Apr 27 15:09:44 2016 : Info: ++[suffix] = noop
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Looking up realm "domain" for
User-Name = "domain\my_ad_user"
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Found realm "domain"
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Adding Stripped-User-Name =
"my_ad_user"
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Adding Realm = "domain"
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Authentication realm is LOCAL.
Wed Apr 27 15:09:44 2016 : Info: ++[ntdomain] = ok
Wed Apr 27 15:09:44 2016 : Info: ++[preprocess] = ok
Wed Apr 27 15:09:44 2016 : Info: [eap] EAP packet type response id 2 length 23
Wed Apr 27 15:09:44 2016 : Info: [eap] No EAP Start, assuming it's an on-going
EAP conversation
Wed Apr 27 15:09:44 2016 : Info: ++[eap] = updated
Wed Apr 27 15:09:44 2016 : Info: ++[files] = noop
Wed Apr 27 15:09:44 2016 : Info: ++[expiration] = noop
Wed Apr 27 15:09:44 2016 : Info: ++[logintime] = noop
Wed Apr 27 15:09:44 2016 : Info: ++update request {
Wed Apr 27 15:09:44 2016 : Info: expand: %{Packet-Src-IP-Address} ->
10.1.10.234
Wed Apr 27 15:09:44 2016 : Info: ++} # update request = noop
Wed Apr 27 15:09:44 2016 : Info: ++update control {
Wed Apr 27 15:09:44 2016 : Info: ++} # update control = noop
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair NAS-Port-Type =
Wireless-802.11
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Service-Type =
Framed-User
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Called-Station-Id =
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Message-Authenticator =
0x0096266da4af2bfdbbf5c8b92cdf61ef
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Vendor-25053-Attr-3 =
0x5061636b657466656e6365
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Called-Station-SSID =
Packetfence
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Connect-Info = CONNECT
802.11a/n
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Realm = domain
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair EAP-Type = Identity
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair NAS-IP-Address =
10.1.10.234
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Calling-Station-Id =
8c:70:5a:05:81:7c
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair
FreeRADIUS-Client-IP-Address = 10.1.10.234
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair User-Name =
domain\\my_ad_user
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair NAS-Identifier =
84-18-3A-3A-12-AC
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair EAP-Message =
0x02020017015155414c59534f46545c676261726f637369
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair NAS-Port = 79
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Stripped-User-Name =
my_ad_user
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Framed-MTU = 1400
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-Pass =
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-Server =
127.0.0.1
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-Proto =
http
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-User =
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair Auth-Type = EAP
Wed Apr 27 15:09:44 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-Port =
7070
Wed Apr 27 15:09:44 2016 : Info: ++[packetfence] = noop
Wed Apr 27 15:09:44 2016 : Info: +} # group authorize = updated
Wed Apr 27 15:09:44 2016 : Info: Found Auth-Type = EAP
Wed Apr 27 15:09:44 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:44 2016 : Info: +group authenticate {
Wed Apr 27 15:09:44 2016 : Info: [eap] EAP Identity
Wed Apr 27 15:09:44 2016 : Info: [eap] processing type tls
Wed Apr 27 15:09:44 2016 : Info: [tls] Initiate
Wed Apr 27 15:09:44 2016 : Info: [tls] Start returned 1
Wed Apr 27 15:09:44 2016 : Info: ++[eap] = handled
Wed Apr 27 15:09:44 2016 : Info: +} # group authenticate = handled
Wed Apr 27 15:09:44 2016 : Info: } # server packetfence
Sending Access-Challenge of id 188 to 10.1.10.234 port 33734
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc405c4c5c406ddecc4c51f08d6d18f3f
Wed Apr 27 15:09:44 2016 : Info: Finished request 0.
Wed Apr 27 15:09:44 2016 : Debug: Going to the next request
Wed Apr 27 15:09:44 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.10.234 port 33734, id=189,
length=328
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8C-70-5A-05-81-7C"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84-18-3A-3A-12-AC:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
EAP-Message =
0x0203007119800000006716030100620100005e03015720ba31f7264af3a5a70d06ec662276a91fa3c3899eb75d90d56d0e1d7f7d3d000018c014c0130035002d000a0006000400170018000b000201000023000000170000ff01000100
State = 0xc405c4c5c406ddecc4c51f08d6d18f3f
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Message-Authenticator = 0x3e755cd12b2728c41c1cf4e1afa7ca64
Wed Apr 27 15:09:44 2016 : Info: server packetfence {
Wed Apr 27 15:09:44 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:44 2016 : Info: +group authorize {
Wed Apr 27 15:09:44 2016 : Info: ++policy rewrite.calling_station_id {
Wed Apr 27 15:09:44 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Wed Apr 27 15:09:44 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: expand: %{Calling-Station-Id} ->
8C-70-5A-05-81-7C
Wed Apr 27 15:09:44 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:44 2016 : Info: expand: ^%{config:policy.mac-addr}$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([-f]?([0-9a-f]{2})$
Wed Apr 27 15:09:44 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~
/^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: +++if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Wed Apr 27 15:09:44 2016 : Info: ++++update request {
Wed Apr 27 15:09:44 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 8C:70:5A:05:81:7C
Wed Apr 27 15:09:44 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 8c:70:5a:05:81:7c
Wed Apr 27 15:09:44 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:44 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:44 2016 : Info: +++} # if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Wed Apr 27 15:09:44 2016 : Info: +++ ... skipping else for request 1: Preceding
"if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++} # policy rewrite.calling_station_id =
updated
Wed Apr 27 15:09:44 2016 : Info: ++policy set.called_station_ssid {
Wed Apr 27 15:09:44 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i)
Wed Apr 27 15:09:44 2016 : Info: ?? Evaluating (Called-Station-Id) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: expand: %{Called-Station-Id} ->
84-18-3A-3A-12-AC:Packetfence
Wed Apr 27 15:09:44 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:44 2016 : Info: expand:
^%{config:policy.mac-addr}(:(.+))?$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$
Wed Apr 27 15:09:44 2016 : Info: ? Evaluating ("%{Called-Station-Id}" =~
/^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:44 2016 : Info: +++if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) {
Wed Apr 27 15:09:44 2016 : Info: ++++update request {
Wed Apr 27 15:09:44 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 84:18:3A:3A:12:AC
Wed Apr 27 15:09:44 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 84:18:3a:3a:12:ac
Wed Apr 27 15:09:44 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:44 2016 : Info: ++++? if ("%{8}")
Wed Apr 27 15:09:44 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:44 2016 : Info: ? Evaluating ("%{8}") -> TRUE
Wed Apr 27 15:09:44 2016 : Info: ++++? if ("%{8}") -> TRUE
Wed Apr 27 15:09:44 2016 : Info: ++++if ("%{8}") {
Wed Apr 27 15:09:44 2016 : Info: +++++update request {
Wed Apr 27 15:09:44 2016 : Info: expand: %{Called-Station-Id}:%{8} ->
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:44 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:44 2016 : Info: +++++} # update request = noop
Wed Apr 27 15:09:44 2016 : Info: ++++} # if ("%{8}") = noop
Wed Apr 27 15:09:44 2016 : Info: ++++ ... skipping elsif for request 1:
Preceding "if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++++ ... skipping elsif for request 1:
Preceding "if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++++ ... skipping elsif for request 1:
Preceding "if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:44 2016 : Info: +++} # if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) = updated
Wed Apr 27 15:09:44 2016 : Info: +++ ... skipping else for request 1: Preceding
"if" was taken
Wed Apr 27 15:09:44 2016 : Info: ++} # policy set.called_station_ssid = updated
Wed Apr 27 15:09:44 2016 : Info: [suffix] No '@' in User-Name =
"domain\my_ad_user", skipping NULL due to config.
Wed Apr 27 15:09:44 2016 : Info: ++[suffix] = noop
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Looking up realm "domain" for
User-Name = "domain\my_ad_user"
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Found realm "domain"
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Adding Stripped-User-Name =
"my_ad_user"
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Adding Realm = "domain"
Wed Apr 27 15:09:44 2016 : Info: [ntdomain] Authentication realm is LOCAL.
Wed Apr 27 15:09:44 2016 : Info: ++[ntdomain] = ok
Wed Apr 27 15:09:44 2016 : Info: ++[preprocess] = ok
Wed Apr 27 15:09:44 2016 : Info: [eap] EAP packet type response id 3 length 113
Wed Apr 27 15:09:44 2016 : Info: [eap] Continuing tunnel setup.
Wed Apr 27 15:09:44 2016 : Info: ++[eap] = ok
Wed Apr 27 15:09:44 2016 : Info: +} # group authorize = ok
Wed Apr 27 15:09:44 2016 : Info: Found Auth-Type = EAP
Wed Apr 27 15:09:44 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:44 2016 : Info: +group authenticate {
Wed Apr 27 15:09:44 2016 : Info: [eap] Request found, released from the list
Wed Apr 27 15:09:44 2016 : Info: [eap] EAP/peap
Wed Apr 27 15:09:44 2016 : Info: [eap] processing type peap
Wed Apr 27 15:09:44 2016 : Info: [peap] processing EAP-TLS
Wed Apr 27 15:09:44 2016 : Debug: TLS Length 103
Wed Apr 27 15:09:44 2016 : Info: [peap] Length Included
Wed Apr 27 15:09:44 2016 : Info: [peap] eaptls_verify returned 11
Wed Apr 27 15:09:44 2016 : Info: [peap] (other): before/accept
initialization
Wed Apr 27 15:09:44 2016 : Info: [peap] TLS_accept: before/accept
initialization
Wed Apr 27 15:09:44 2016 : Info: [peap] <<< TLS 1.0 Handshake [length 0062],
ClientHello
Wed Apr 27 15:09:44 2016 : Info: [peap] TLS_accept: SSLv3 read client hello
A
Wed Apr 27 15:09:44 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 0039],
ServerHello
Wed Apr 27 15:09:44 2016 : Info: [peap] TLS_accept: SSLv3 write server
hello A
Wed Apr 27 15:09:44 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 065f],
Certificate
Wed Apr 27 15:09:44 2016 : Info: [peap] TLS_accept: SSLv3 write certificate
A
Wed Apr 27 15:09:44 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 014b],
ServerKeyExchange
Wed Apr 27 15:09:44 2016 : Info: [peap] TLS_accept: SSLv3 write key
exchange A
Wed Apr 27 15:09:44 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 0004],
ServerHelloDone
Wed Apr 27 15:09:44 2016 : Info: [peap] TLS_accept: SSLv3 write server done
A
Wed Apr 27 15:09:44 2016 : Info: [peap] TLS_accept: SSLv3 flush data
Wed Apr 27 15:09:44 2016 : Info: [peap] TLS_accept: Need to read more data:
SSLv3 read client certificate A
Wed Apr 27 15:09:44 2016 : Info: [peap] TLS_accept: Need to read more data:
SSLv3 read client certificate A
Wed Apr 27 15:09:44 2016 : Debug: In SSL Handshake Phase
Wed Apr 27 15:09:44 2016 : Debug: In SSL Accept mode
Wed Apr 27 15:09:44 2016 : Info: [peap] eaptls_process returned 13
Wed Apr 27 15:09:44 2016 : Info: [peap] EAPTLS_HANDLED
Wed Apr 27 15:09:44 2016 : Info: ++[eap] = handled
Wed Apr 27 15:09:44 2016 : Info: +} # group authenticate = handled
Wed Apr 27 15:09:44 2016 : Info: } # server packetfence
Sending Access-Challenge of id 189 to 10.1.10.234 port 33734
EAP-Message =
0x0104040019c0000007fb16030100390200003503015720ba18f5427256e81ce1432d5e7efcd57aacb72a5c9031eda68adc4e84eea200c01400000dff010001080006553082065130820539a003020102020a3d7491f60000002ceb92300d06092a864886f70d01010b0500304d31123010060a0992268993f22c6401191602687531193017060a099226891a060355040313135175616c79736f6674204f6e6c696e65204341301e170d3136303330343131333832325a170d3138303330343131333832325a302431223020060355040313197061
EAP-Message =
0x636b657466656e63652e7175616c79736f66742e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100c722c7fe48ea2b885d2dd1557c0753e0c088711310526bf3073ee4dcc2a1cd59ec8ae4e626afb209240d3ddabc7ffe5e0c0130d854aa6f17cdac68abd422935ea4e252ba401f3e3053467a0105f6c4bc7f4cce0e8d533245bc58e6f57f008aa8fa9db9b2d13ac3aac908def8a79c8adde431d8359f0b0691b21084fef3c03631558816349866ebe74169af8378466755085d8ff57bcabd5d25ba6009e4
EAP-Message =
0xe0f5bf65b460edd31fc467f3fce0536ae8d53f84652bd59f68cc647a22c622c98487828ac1912a79c9628bc657e3f8d581d88b69635a55ceb1927d0203010005070431302f06272b060104018237150885a6904c82cfce0b85d19f09879dcc0b87b4e17d813385dd900285e0a71b020164020105301d0603551d250416301406082b060105050703010608a0302706092b060104018237150a041a3018300a06082b06010505070301300a06082b06010505070302301d0603551d0e04160414d5446815e46d11087b82fd4f07f720fbea41331530
EAP-Message =
0x230603551d11041c301a82187061636b657466656e63652e7175616c79736f66742e6875301f0603551d2304183016801422e386ff6644f78d9f47a9af10a5a2010a30820106a0820102a081ff8681c26c6461703a2f2f2f434e3d5175616c79736f66742532304f6e6c696e6525323043412c434e3d4250564d5343415030312c434e3d4344502c434e3d6365732c434e3d53657276696365732c434e3d436f6e66696775726174696f6e2c44433d7175616c79736f66742c44433d68753f63657274696669636174655265766f636174696f6e4c
EAP-Message = 0x6973743f626173653f6f626a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc405c4c5c501ddecc4c51f08d6d18f3f
Wed Apr 27 15:09:44 2016 : Info: Finished request 1.
Wed Apr 27 15:09:44 2016 : Debug: Going to the next request
Wed Apr 27 15:09:44 2016 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.1.10.234 port 33734, id=190,
length=221
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8C-70-5A-05-81-7C"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84-18-3A-3A-12-AC:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
EAP-Message = 0x020400061900
State = 0xc405c4c5c501ddecc4c51f08d6d18f3f
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Message-Authenticator = 0x37d70352cc37306e58a6a34164ec2891
Wed Apr 27 15:09:47 2016 : Info: server packetfence {
Wed Apr 27 15:09:47 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authorize {
Wed Apr 27 15:09:47 2016 : Info: ++policy rewrite.calling_station_id {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Calling-Station-Id} ->
8C-70-5A-05-81-7C
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand: ^%{config:policy.mac-addr}$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([-f]?([0-9a-f]{2})$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~
/^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 8C:70:5A:05:81:7C
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 8c:70:5a:05:81:7c
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 2: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy rewrite.calling_station_id =
updated
Wed Apr 27 15:09:47 2016 : Info: ++policy set.called_station_ssid {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Called-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id} ->
84-18-3A-3A-12-AC:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand:
^%{config:policy.mac-addr}(:(.+))?$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Called-Station-Id}" =~
/^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 84:18:3A:3A:12:AC
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 84:18:3a:3a:12:ac
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}")
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++if ("%{8}") {
Wed Apr 27 15:09:47 2016 : Info: +++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id}:%{8} ->
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: +++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++} # if ("%{8}") = noop
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 2:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 2:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 2:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 2: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy set.called_station_ssid = updated
Wed Apr 27 15:09:47 2016 : Info: [suffix] No '@' in User-Name =
"domain\my_ad_user", skipping NULL due to config.
Wed Apr 27 15:09:47 2016 : Info: ++[suffix] = noop
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Looking up realm "domain" for
User-Name = "domain\my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Found realm "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Stripped-User-Name =
"my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Realm = "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Authentication realm is LOCAL.
Wed Apr 27 15:09:47 2016 : Info: ++[ntdomain] = ok
Wed Apr 27 15:09:47 2016 : Info: ++[preprocess] = ok
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP packet type response id 4 length 6
Wed Apr 27 15:09:47 2016 : Info: [eap] Continuing tunnel setup.
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = ok
Wed Apr 27 15:09:47 2016 : Info: +} # group authorize = ok
Wed Apr 27 15:09:47 2016 : Info: Found Auth-Type = EAP
Wed Apr 27 15:09:47 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authenticate {
Wed Apr 27 15:09:47 2016 : Info: [eap] Request found, released from the list
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP/peap
Wed Apr 27 15:09:47 2016 : Info: [eap] processing type peap
Wed Apr 27 15:09:47 2016 : Info: [peap] processing EAP-TLS
Wed Apr 27 15:09:47 2016 : Info: [peap] Received TLS ACK
Wed Apr 27 15:09:47 2016 : Info: [peap] ACK handshake fragment handler
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_verify returned 1
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_process returned 13
Wed Apr 27 15:09:47 2016 : Info: [peap] EAPTLS_HANDLED
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = handled
Wed Apr 27 15:09:47 2016 : Info: +} # group authenticate = handled
Wed Apr 27 15:09:47 2016 : Info: } # server packetfence
Sending Access-Challenge of id 190 to 10.1.10.234 port 33734
EAP-Message =
0x010503fc1940656374436c6173733d63524c446973747269627574696f6e506f696e748638687474703a2f2f63726c2e7175616c79736f66742e636f6d2f636525323043412e63726c3082013d06082b060105050701010482012f3082012b3081b706082b060105050730028681aa6c6461703a2f2f2f434e3d5175616c79736f66742532304f6e6c696e6c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d436f6e66696775726174696f6e2c44433d7175616c79736f66742c44433d68753f6341436572
EAP-Message =
0x74696669636174653f626173653f6f626a656374436c6173733d63657274696669636174696f6e417574686f72697479302906082b06010505073001861d68736f6d2f6f637370304406082b060105050730028638687474703a2f2f63726c2e7175616c79736f66742e636f6d2f6169612f5175616c79736f66742532304f6e6c696e6525323043412e6301009b34454869e8c9667753ce01a0f853b98a28e3b978a14faf7cfa1373f09a0a8e970afe3a1de315f63328ca3797ceb7ca0bcc26a191c172d670e19d76792ca04755ca5fcd888f3370
EAP-Message =
0xd519dc5627e4443d84aa82c1f8d4a1280aa2fa67035ffb07b6f807134836a53d814f403e29c919c6719b959a9450a920532817b2995622d5a44ca4bbdec4309d6400eb230042f993f66d18a3edaef9a2302b0c57f3f9ad9dbe37892d6b40542c2bda26f85abd7e717308d4bfa7787d13893ad569e38ed8148ff99921e69f0ba0a001ccd510016d06f5dd87b4d621dc1c160301014b0c0001470300174104ddb0ba4e37718356d2afb2ca84b3338584761cc7da76452fa2d98e17975901f9b481314ef1cf90d79f6b0790673fbf5490b8d532b15fef
EAP-Message =
0x89e7e3f88adccc63c90100252befb2197e54299be90b365e288ef7991c390045b3f54ddf1f5eb8397d764268d579960d033aeb8aeb83afde096904d0abec52bed098a7c42c3405441895effac7483fe34d7698fdbe24459bdd385e50fca8fa273380b09505f8bcbd1fc9ea258c717cf2e296f89016f1607831ac9eee74c7cf82868a49d324dc0d2c8bec22a0cea7f70b6f3830f7d3d20d01040c30d82b24cd143b4e06585aec0dc64bc032dfbba6f0760478acc3e7ebc46000ed6689e2473ee1153323876aac7156fbd7de514bb268a03fac642271
EAP-Message = 0x9bc406c00ce38890
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc405c4c5c600ddecc4c51f08d6d18f3f
Wed Apr 27 15:09:47 2016 : Info: Finished request 2.
Wed Apr 27 15:09:47 2016 : Debug: Going to the next request
Wed Apr 27 15:09:47 2016 : Debug: Waking up in 1.8 seconds.
rad_recv: Access-Request packet from host 10.1.10.234 port 33734, id=191,
length=221
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8C-70-5A-05-81-7C"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84-18-3A-3A-12-AC:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
EAP-Message = 0x020500061900
State = 0xc405c4c5c600ddecc4c51f08d6d18f3f
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Message-Authenticator = 0xfdf4cab5c9503baa168c77bafe8076b7
Wed Apr 27 15:09:47 2016 : Info: server packetfence {
Wed Apr 27 15:09:47 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authorize {
Wed Apr 27 15:09:47 2016 : Info: ++policy rewrite.calling_station_id {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Calling-Station-Id} ->
8C-70-5A-05-81-7C
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand: ^%{config:policy.mac-addr}$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([-f]?([0-9a-f]{2})$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~
/^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 8C:70:5A:05:81:7C
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 8c:70:5a:05:81:7c
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 3: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy rewrite.calling_station_id =
updated
Wed Apr 27 15:09:47 2016 : Info: ++policy set.called_station_ssid {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Called-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id} ->
84-18-3A-3A-12-AC:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand:
^%{config:policy.mac-addr}(:(.+))?$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Called-Station-Id}" =~
/^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 84:18:3A:3A:12:AC
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 84:18:3a:3a:12:ac
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}")
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++if ("%{8}") {
Wed Apr 27 15:09:47 2016 : Info: +++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id}:%{8} ->
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: +++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++} # if ("%{8}") = noop
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 3:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 3:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 3:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 3: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy set.called_station_ssid = updated
Wed Apr 27 15:09:47 2016 : Info: [suffix] No '@' in User-Name =
"domain\my_ad_user", skipping NULL due to config.
Wed Apr 27 15:09:47 2016 : Info: ++[suffix] = noop
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Looking up realm "domain" for
User-Name = "domain\my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Found realm "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Stripped-User-Name =
"my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Realm = "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Authentication realm is LOCAL.
Wed Apr 27 15:09:47 2016 : Info: ++[ntdomain] = ok
Wed Apr 27 15:09:47 2016 : Info: ++[preprocess] = ok
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP packet type response id 5 length 6
Wed Apr 27 15:09:47 2016 : Info: [eap] Continuing tunnel setup.
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = ok
Wed Apr 27 15:09:47 2016 : Info: +} # group authorize = ok
Wed Apr 27 15:09:47 2016 : Info: Found Auth-Type = EAP
Wed Apr 27 15:09:47 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authenticate {
Wed Apr 27 15:09:47 2016 : Info: [eap] Request found, released from the list
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP/peap
Wed Apr 27 15:09:47 2016 : Info: [eap] processing type peap
Wed Apr 27 15:09:47 2016 : Info: [peap] processing EAP-TLS
Wed Apr 27 15:09:47 2016 : Info: [peap] Received TLS ACK
Wed Apr 27 15:09:47 2016 : Info: [peap] ACK handshake fragment handler
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_verify returned 1
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_process returned 13
Wed Apr 27 15:09:47 2016 : Info: [peap] EAPTLS_HANDLED
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = handled
Wed Apr 27 15:09:47 2016 : Info: +} # group authenticate = handled
Wed Apr 27 15:09:47 2016 : Info: } # server packetfence
Sending Access-Challenge of id 191 to 10.1.10.234 port 33734
EAP-Message = 0x010600151900f8942a27aba416030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc405c4c5c703ddecc4c51f08d6d18f3f
Wed Apr 27 15:09:47 2016 : Info: Finished request 3.
Wed Apr 27 15:09:47 2016 : Debug: Going to the next request
Wed Apr 27 15:09:47 2016 : Debug: Waking up in 1.8 seconds.
rad_recv: Access-Request packet from host 10.1.10.234 port 33734, id=192,
length=359
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8C-70-5A-05-81-7C"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84-18-3A-3A-12-AC:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
EAP-Message =
0x02060090198000000086160301004610000042410426568e3399ac493fadce8e45f5ead9449a1c4bab69ff34ee1cde4476a08ff368f31c86d491ee48dfeab0cc0314030100010116030100308b3e5763dc4ac936bb1238176ea64e6b6e90af9644500f73038050fc292e44ac418ae0a26764cb9886a0ac46c5612ab1
State = 0xc405c4c5c703ddecc4c51f08d6d18f3f
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Message-Authenticator = 0x400e0509202ccde396a6f1fd3404094d
Wed Apr 27 15:09:47 2016 : Info: server packetfence {
Wed Apr 27 15:09:47 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authorize {
Wed Apr 27 15:09:47 2016 : Info: ++policy rewrite.calling_station_id {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Calling-Station-Id} ->
8C-70-5A-05-81-7C
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand: ^%{config:policy.mac-addr}$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([-f]?([0-9a-f]{2})$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~
/^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 8C:70:5A:05:81:7C
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 8c:70:5a:05:81:7c
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 4: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy rewrite.calling_station_id =
updated
Wed Apr 27 15:09:47 2016 : Info: ++policy set.called_station_ssid {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Called-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id} ->
84-18-3A-3A-12-AC:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand:
^%{config:policy.mac-addr}(:(.+))?$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Called-Station-Id}" =~
/^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 84:18:3A:3A:12:AC
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 84:18:3a:3a:12:ac
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}")
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++if ("%{8}") {
Wed Apr 27 15:09:47 2016 : Info: +++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id}:%{8} ->
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: +++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++} # if ("%{8}") = noop
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 4:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 4:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 4:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 4: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy set.called_station_ssid = updated
Wed Apr 27 15:09:47 2016 : Info: [suffix] No '@' in User-Name =
"domain\my_ad_user", skipping NULL due to config.
Wed Apr 27 15:09:47 2016 : Info: ++[suffix] = noop
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Looking up realm "domain" for
User-Name = "domain\my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Found realm "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Stripped-User-Name =
"my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Realm = "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Authentication realm is LOCAL.
Wed Apr 27 15:09:47 2016 : Info: ++[ntdomain] = ok
Wed Apr 27 15:09:47 2016 : Info: ++[preprocess] = ok
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP packet type response id 6 length 144
Wed Apr 27 15:09:47 2016 : Info: [eap] Continuing tunnel setup.
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = ok
Wed Apr 27 15:09:47 2016 : Info: +} # group authorize = ok
Wed Apr 27 15:09:47 2016 : Info: Found Auth-Type = EAP
Wed Apr 27 15:09:47 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authenticate {
Wed Apr 27 15:09:47 2016 : Info: [eap] Request found, released from the list
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP/peap
Wed Apr 27 15:09:47 2016 : Info: [eap] processing type peap
Wed Apr 27 15:09:47 2016 : Info: [peap] processing EAP-TLS
Wed Apr 27 15:09:47 2016 : Debug: TLS Length 134
Wed Apr 27 15:09:47 2016 : Info: [peap] Length Included
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_verify returned 11
Wed Apr 27 15:09:47 2016 : Info: [peap] <<< TLS 1.0 Handshake [length 0046],
ClientKeyExchange
Wed Apr 27 15:09:47 2016 : Info: [peap] TLS_accept: SSLv3 read client key
exchange A
Wed Apr 27 15:09:47 2016 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length
0001]
Wed Apr 27 15:09:47 2016 : Info: [peap] <<< TLS 1.0 Handshake [length 0010],
Finished
Wed Apr 27 15:09:47 2016 : Info: [peap] TLS_accept: SSLv3 read finished A
Wed Apr 27 15:09:47 2016 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length
0001]
Wed Apr 27 15:09:47 2016 : Info: [peap] TLS_accept: SSLv3 write change
cipher spec A
Wed Apr 27 15:09:47 2016 : Info: [peap] >>> TLS 1.0 Handshake [length 0010],
Finished
Wed Apr 27 15:09:47 2016 : Info: [peap] TLS_accept: SSLv3 write finished A
Wed Apr 27 15:09:47 2016 : Info: [peap] TLS_accept: SSLv3 flush data
Wed Apr 27 15:09:47 2016 : Info: [peap] (other): SSL negotiation finished
successfully
Wed Apr 27 15:09:47 2016 : Debug: SSL Connection Established
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_process returned 13
Wed Apr 27 15:09:47 2016 : Info: [peap] EAPTLS_HANDLED
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = handled
Wed Apr 27 15:09:47 2016 : Info: +} # group authenticate = handled
Wed Apr 27 15:09:47 2016 : Info: } # server packetfence
Sending Access-Challenge of id 192 to 10.1.10.234 port 33734
EAP-Message =
0x0107004119001403010001011603010030eaa5207b9d12c7cbf2843362322109f0e995f99090b7ea9678f9359d1ee63048661739561d3abca6a97d4f06d7769
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc405c4c5c002ddecc4c51f08d6d18f3f
Wed Apr 27 15:09:47 2016 : Info: Finished request 4.
Wed Apr 27 15:09:47 2016 : Debug: Going to the next request
Wed Apr 27 15:09:47 2016 : Debug: Waking up in 1.7 seconds.
rad_recv: Access-Request packet from host 10.1.10.234 port 33734, id=193,
length=221
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8C-70-5A-05-81-7C"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84-18-3A-3A-12-AC:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
EAP-Message = 0x020700061900
State = 0xc405c4c5c002ddecc4c51f08d6d18f3f
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Message-Authenticator = 0xaab3b1b9fd039f1c8291bc12650b3ace
Wed Apr 27 15:09:47 2016 : Info: server packetfence {
Wed Apr 27 15:09:47 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authorize {
Wed Apr 27 15:09:47 2016 : Info: ++policy rewrite.calling_station_id {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Calling-Station-Id} ->
8C-70-5A-05-81-7C
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand: ^%{config:policy.mac-addr}$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([-f]?([0-9a-f]{2})$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~
/^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 8C:70:5A:05:81:7C
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 8c:70:5a:05:81:7c
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 5: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy rewrite.calling_station_id =
updated
Wed Apr 27 15:09:47 2016 : Info: ++policy set.called_station_ssid {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Called-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id} ->
84-18-3A-3A-12-AC:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand:
^%{config:policy.mac-addr}(:(.+))?$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Called-Station-Id}" =~
/^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 84:18:3A:3A:12:AC
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 84:18:3a:3a:12:ac
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}")
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++if ("%{8}") {
Wed Apr 27 15:09:47 2016 : Info: +++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id}:%{8} ->
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: +++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++} # if ("%{8}") = noop
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 5:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 5:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 5:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 5: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy set.called_station_ssid = updated
Wed Apr 27 15:09:47 2016 : Info: [suffix] No '@' in User-Name =
"domain\my_ad_user", skipping NULL due to config.
Wed Apr 27 15:09:47 2016 : Info: ++[suffix] = noop
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Looking up realm "domain" for
User-Name = "domain\my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Found realm "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Stripped-User-Name =
"my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Realm = "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Authentication realm is LOCAL.
Wed Apr 27 15:09:47 2016 : Info: ++[ntdomain] = ok
Wed Apr 27 15:09:47 2016 : Info: ++[preprocess] = ok
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP packet type response id 7 length 6
Wed Apr 27 15:09:47 2016 : Info: [eap] Continuing tunnel setup.
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = ok
Wed Apr 27 15:09:47 2016 : Info: +} # group authorize = ok
Wed Apr 27 15:09:47 2016 : Info: Found Auth-Type = EAP
Wed Apr 27 15:09:47 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authenticate {
Wed Apr 27 15:09:47 2016 : Info: [eap] Request found, released from the list
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP/peap
Wed Apr 27 15:09:47 2016 : Info: [eap] processing type peap
Wed Apr 27 15:09:47 2016 : Info: [peap] processing EAP-TLS
Wed Apr 27 15:09:47 2016 : Info: [peap] Received TLS ACK
Wed Apr 27 15:09:47 2016 : Info: [peap] ACK handshake is finished
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_verify returned 3
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_process returned 3
Wed Apr 27 15:09:47 2016 : Info: [peap] EAPTLS_SUCCESS
Wed Apr 27 15:09:47 2016 : Info: [peap] Session established. Decoding tunneled
attributes.
Wed Apr 27 15:09:47 2016 : Info: [peap] Peap state TUNNEL ESTABLISHED
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = handled
Wed Apr 27 15:09:47 2016 : Info: +} # group authenticate = handled
Wed Apr 27 15:09:47 2016 : Info: } # server packetfence
Sending Access-Challenge of id 193 to 10.1.10.234 port 33734
EAP-Message =
0x0108002b19001703010020748fb9edd9f68487584e87b71b60a16c480593e1a1abc4070e20025fbfa0b751
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc405c4c5c10dddecc4c51f08d6d18f3f
Wed Apr 27 15:09:47 2016 : Info: Finished request 5.
Wed Apr 27 15:09:47 2016 : Debug: Going to the next request
Wed Apr 27 15:09:47 2016 : Debug: Waking up in 1.7 seconds.
rad_recv: Access-Request packet from host 10.1.10.234 port 33734, id=194,
length=274
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8C-70-5A-05-81-7C"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84-18-3A-3A-12-AC:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
EAP-Message =
0x0208003b1900170301003075bfcbc1677fe7afd223d3b5aade7909e0ed42167dee5b73102d1048f8b4ae64b9295633b22ce6644c6da42404fc7b95
State = 0xc405c4c5c10dddecc4c51f08d6d18f3f
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Message-Authenticator = 0x8cb357a35c350f3bc038471ced2f5317
Wed Apr 27 15:09:47 2016 : Info: server packetfence {
Wed Apr 27 15:09:47 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authorize {
Wed Apr 27 15:09:47 2016 : Info: ++policy rewrite.calling_station_id {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Calling-Station-Id} ->
8C-70-5A-05-81-7C
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand: ^%{config:policy.mac-addr}$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([-f]?([0-9a-f]{2})$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~
/^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 8C:70:5A:05:81:7C
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 8c:70:5a:05:81:7c
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 6: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy rewrite.calling_station_id =
updated
Wed Apr 27 15:09:47 2016 : Info: ++policy set.called_station_ssid {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Called-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id} ->
84-18-3A-3A-12-AC:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand:
^%{config:policy.mac-addr}(:(.+))?$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Called-Station-Id}" =~
/^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 84:18:3A:3A:12:AC
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 84:18:3a:3a:12:ac
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}")
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++if ("%{8}") {
Wed Apr 27 15:09:47 2016 : Info: +++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id}:%{8} ->
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: +++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++} # if ("%{8}") = noop
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 6:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 6:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 6:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 6: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy set.called_station_ssid = updated
Wed Apr 27 15:09:47 2016 : Info: [suffix] No '@' in User-Name =
"domain\my_ad_user", skipping NULL due to config.
Wed Apr 27 15:09:47 2016 : Info: ++[suffix] = noop
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Looking up realm "domain" for
User-Name = "domain\my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Found realm "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Stripped-User-Name =
"my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Realm = "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Authentication realm is LOCAL.
Wed Apr 27 15:09:47 2016 : Info: ++[ntdomain] = ok
Wed Apr 27 15:09:47 2016 : Info: ++[preprocess] = ok
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP packet type response id 8 length 59
Wed Apr 27 15:09:47 2016 : Info: [eap] Continuing tunnel setup.
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = ok
Wed Apr 27 15:09:47 2016 : Info: +} # group authorize = ok
Wed Apr 27 15:09:47 2016 : Info: Found Auth-Type = EAP
Wed Apr 27 15:09:47 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authenticate {
Wed Apr 27 15:09:47 2016 : Info: [eap] Request found, released from the list
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP/peap
Wed Apr 27 15:09:47 2016 : Info: [eap] processing type peap
Wed Apr 27 15:09:47 2016 : Info: [peap] processing EAP-TLS
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_verify returned 7
Wed Apr 27 15:09:47 2016 : Info: [peap] Done initial handshake
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_process returned 7
Wed Apr 27 15:09:47 2016 : Info: [peap] EAPTLS_OK
Wed Apr 27 15:09:47 2016 : Info: [peap] Session established. Decoding tunneled
attributes.
Wed Apr 27 15:09:47 2016 : Info: [peap] Peap state WAITING FOR INNER IDENTITY
Wed Apr 27 15:09:47 2016 : Info: [peap] Identity - domain\my_ad_user
Wed Apr 27 15:09:47 2016 : Info: [peap] Got inner identity 'domain\my_ad_user'
Wed Apr 27 15:09:47 2016 : Info: [peap] Requesting SoH from client
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = handled
Wed Apr 27 15:09:47 2016 : Info: +} # group authenticate = handled
Wed Apr 27 15:09:47 2016 : Info: } # server packetfence
Sending Access-Challenge of id 194 to 10.1.10.234 port 33734
EAP-Message =
0x0109003b19001703010030839338c4a582451a4395a935a2fc7335024a3e545fb81ecfa81ca2ccdb83c5fe2a02996bdfebf0b7e921a39a69b26d1a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc405c4c5c20cddecc4c51f08d6d18f3f
Wed Apr 27 15:09:47 2016 : Info: Finished request 6.
Wed Apr 27 15:09:47 2016 : Debug: Going to the next request
Wed Apr 27 15:09:47 2016 : Debug: Waking up in 1.7 seconds.
rad_recv: Access-Request packet from host 10.1.10.234 port 33734, id=195,
length=258
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8C-70-5A-05-81-7C"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84-18-3A-3A-12-AC:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
EAP-Message =
0x0209002b190017030100202240c798e666c8aecd3b73132123ad1f657fabceb7272c000f41c88b294f3e53
State = 0xc405c4c5c20cddecc4c51f08d6d18f3f
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Message-Authenticator = 0x311337cfe7061ca5caa56402835b4b23
Wed Apr 27 15:09:47 2016 : Info: server packetfence {
Wed Apr 27 15:09:47 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authorize {
Wed Apr 27 15:09:47 2016 : Info: ++policy rewrite.calling_station_id {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Calling-Station-Id} ->
8C-70-5A-05-81-7C
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand: ^%{config:policy.mac-addr}$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([-f]?([0-9a-f]{2})$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~
/^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 8C:70:5A:05:81:7C
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 8c:70:5a:05:81:7c
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 7: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy rewrite.calling_station_id =
updated
Wed Apr 27 15:09:47 2016 : Info: ++policy set.called_station_ssid {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Called-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id} ->
84-18-3A-3A-12-AC:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand:
^%{config:policy.mac-addr}(:(.+))?$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Called-Station-Id}" =~
/^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 84:18:3A:3A:12:AC
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 84:18:3a:3a:12:ac
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}")
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++if ("%{8}") {
Wed Apr 27 15:09:47 2016 : Info: +++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id}:%{8} ->
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: +++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++} # if ("%{8}") = noop
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 7:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 7:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 7:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 7: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy set.called_station_ssid = updated
Wed Apr 27 15:09:47 2016 : Info: [suffix] No '@' in User-Name =
"domain\my_ad_user", skipping NULL due to config.
Wed Apr 27 15:09:47 2016 : Info: ++[suffix] = noop
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Looking up realm "domain" for
User-Name = "domain\my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Found realm "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Stripped-User-Name =
"my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Realm = "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Authentication realm is LOCAL.
Wed Apr 27 15:09:47 2016 : Info: ++[ntdomain] = ok
Wed Apr 27 15:09:47 2016 : Info: ++[preprocess] = ok
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP packet type response id 9 length 43
Wed Apr 27 15:09:47 2016 : Info: [eap] Continuing tunnel setup.
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = ok
Wed Apr 27 15:09:47 2016 : Info: +} # group authorize = ok
Wed Apr 27 15:09:47 2016 : Info: Found Auth-Type = EAP
Wed Apr 27 15:09:47 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authenticate {
Wed Apr 27 15:09:47 2016 : Info: [eap] Request found, released from the list
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP/peap
Wed Apr 27 15:09:47 2016 : Info: [eap] processing type peap
Wed Apr 27 15:09:47 2016 : Info: [peap] processing EAP-TLS
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_verify returned 7
Wed Apr 27 15:09:47 2016 : Info: [peap] Done initial handshake
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_process returned 7
Wed Apr 27 15:09:47 2016 : Info: [peap] EAPTLS_OK
Wed Apr 27 15:09:47 2016 : Info: [peap] Session established. Decoding tunneled
attributes.
Wed Apr 27 15:09:47 2016 : Info: [peap] Peap state WAITING FOR SOH RESPONSE
Wed Apr 27 15:09:47 2016 : Info: [peap] EAP type nak
Wed Apr 27 15:09:47 2016 : Info: [peap] SoH - client NAKed
Wed Apr 27 15:09:47 2016 : Info: [peap] Setting User-Name to domain\my_ad_user
Wed Apr 27 15:09:47 2016 : Info: [peap] Processing SoH request
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8c:70:5a:05:81:7c"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84:18:3a:3a:12:ac:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Wed Apr 27 15:09:47 2016 : Info: [peap] server soh-server {
Wed Apr 27 15:09:47 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence-soh
Wed Apr 27 15:09:47 2016 : Info: +group authorize {
Wed Apr 27 15:09:47 2016 : Info: ++update control {
Wed Apr 27 15:09:47 2016 : Info: ++} # update control = noop
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: StatementOfHealth RESULT RESPONSE
CODE: 1 (2 means OK)
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair NAS-Port-Type =
Wireless-802.11
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair Service-Type =
Framed-User
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair Called-Station-Id =
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair Calling-Station-Id =
8c:70:5a:05:81:7c
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair FreeRADIUS-Proxied-To =
127.0.0.1
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair Vendor-25053-Attr-3 =
0x5061636b657466656e6365
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair User-Name =
domain\\my_ad_user
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair NAS-Identifier =
84-18-3A-3A-12-AC
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair Connect-Info = CONNECT
802.11a/n
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair NAS-IP-Address =
10.1.10.234
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair NAS-Port = 79
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair Framed-MTU = 1400
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-Pass =
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-Server =
127.0.0.1
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-Proto =
http
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-User =
Wed Apr 27 15:09:47 2016 : Debug: rlm_perl: Added pair PacketFence-RPC-Port =
7070
Wed Apr 27 15:09:47 2016 : Info: ++[packetfence-soh] = fail
Wed Apr 27 15:09:47 2016 : Info: +} # group authorize = fail
Wed Apr 27 15:09:47 2016 : Auth: Invalid user: [domain\\my_ad_user] (from
client 10.1.10.234 port 79 cli 8c:70:5a:05:81:7c via TLS tunnel)
Wed Apr 27 15:09:47 2016 : Info: Using Post-Auth-Type REJECT
Wed Apr 27 15:09:47 2016 : Info: WARNING: Unknown value specified for
Post-Auth-Type. Cannot perform requested action.
Wed Apr 27 15:09:47 2016 : Info: [peap] } # server soh-server
Wed Apr 27 15:09:47 2016 : Info: [peap] Got SoH reply
Wed Apr 27 15:09:47 2016 : Info: [peap] SoH was rejected
Wed Apr 27 15:09:47 2016 : Info: [peap] FAILURE
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = handled
Wed Apr 27 15:09:47 2016 : Info: +} # group authenticate = handled
Wed Apr 27 15:09:47 2016 : Info: } # server packetfence
Sending Access-Challenge of id 195 to 10.1.10.234 port 33734
EAP-Message =
0x010a002b1900170301002075669351157915b0d98f72fe0483d5e2ec38d8c598fbc0e4d50e6e350075b841
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc405c4c5c30fddecc4c51f08d6d18f3f
Wed Apr 27 15:09:47 2016 : Info: Finished request 7.
Wed Apr 27 15:09:47 2016 : Debug: Going to the next request
Wed Apr 27 15:09:47 2016 : Debug: Waking up in 1.6 seconds.
rad_recv: Access-Request packet from host 10.1.10.234 port 33734, id=196,
length=258
User-Name = "domain\\my_ad_user"
Calling-Station-Id = "8C-70-5A-05-81-7C"
NAS-IP-Address = 10.1.10.234
NAS-Port = 79
Called-Station-Id = "84-18-3A-3A-12-AC:Packetfence"
Service-Type = Framed-User
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
NAS-Identifier = "84-18-3A-3A-12-AC"
Connect-Info = "CONNECT 802.11a/n"
EAP-Message =
0x020a002b190017030100209f782fb2916b1e8714d420d760a419063696090be087f8b7400f1b46d0ec4abe
State = 0xc405c4c5c30fddecc4c51f08d6d18f3f
Vendor-25053-Attr-3 = 0x5061636b657466656e6365
Message-Authenticator = 0x159720f464d7af56dd57d8ecdb37351a
Wed Apr 27 15:09:47 2016 : Info: server packetfence {
Wed Apr 27 15:09:47 2016 : Info: # Executing section authorize from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authorize {
Wed Apr 27 15:09:47 2016 : Info: ++policy rewrite.calling_station_id {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Calling-Station-Id} ->
8C-70-5A-05-81-7C
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand: ^%{config:policy.mac-addr}$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([-f]?([0-9a-f]{2})$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~
/^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 8C:70:5A:05:81:7C
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 8c:70:5a:05:81:7c
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Calling-Station-Id) &&
"%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 8: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy rewrite.calling_station_id =
updated
Wed Apr 27 15:09:47 2016 : Info: ++policy set.called_station_ssid {
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i)
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (Called-Station-Id) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id} ->
84-18-3A-3A-12-AC:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: policy.mac-addr ->
policy.mac-addr
Wed Apr 27 15:09:47 2016 : Info: expand:
^%{config:policy.mac-addr}(:(.+))?$ ->
^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{Called-Station-Id}" =~
/^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++? if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: +++if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) {
Wed Apr 27 15:09:47 2016 : Info: ++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6}
-> 84:18:3A:3A:12:AC
Wed Apr 27 15:09:47 2016 : Info: expand:
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} -> 84:18:3a:3a:12:ac
Wed Apr 27 15:09:47 2016 : Info: ++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}")
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++? if ("%{8}") -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ++++if ("%{8}") {
Wed Apr 27 15:09:47 2016 : Info: +++++update request {
Wed Apr 27 15:09:47 2016 : Info: expand: %{Called-Station-Id}:%{8} ->
84:18:3a:3a:12:ac:Packetfence
Wed Apr 27 15:09:47 2016 : Info: expand: %{8} -> Packetfence
Wed Apr 27 15:09:47 2016 : Info: +++++} # update request = noop
Wed Apr 27 15:09:47 2016 : Info: ++++} # if ("%{8}") = noop
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 8:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 8:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++ ... skipping elsif for request 8:
Preceding "if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++++[updated] = updated
Wed Apr 27 15:09:47 2016 : Info: +++} # if ((Called-Station-Id) &&
"%{Called-Station-Id}" =~ /^%{config:policy.mac-addr}(:(.+))?$/i) = updated
Wed Apr 27 15:09:47 2016 : Info: +++ ... skipping else for request 8: Preceding
"if" was taken
Wed Apr 27 15:09:47 2016 : Info: ++} # policy set.called_station_ssid = updated
Wed Apr 27 15:09:47 2016 : Info: [suffix] No '@' in User-Name =
"domain\my_ad_user", skipping NULL due to config.
Wed Apr 27 15:09:47 2016 : Info: ++[suffix] = noop
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Looking up realm "domain" for
User-Name = "domain\my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Found realm "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Stripped-User-Name =
"my_ad_user"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Adding Realm = "domain"
Wed Apr 27 15:09:47 2016 : Info: [ntdomain] Authentication realm is LOCAL.
Wed Apr 27 15:09:47 2016 : Info: ++[ntdomain] = ok
Wed Apr 27 15:09:47 2016 : Info: ++[preprocess] = ok
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP packet type response id 10 length 43
Wed Apr 27 15:09:47 2016 : Info: [eap] Continuing tunnel setup.
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = ok
Wed Apr 27 15:09:47 2016 : Info: +} # group authorize = ok
Wed Apr 27 15:09:47 2016 : Info: Found Auth-Type = EAP
Wed Apr 27 15:09:47 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group authenticate {
Wed Apr 27 15:09:47 2016 : Info: [eap] Request found, released from the list
Wed Apr 27 15:09:47 2016 : Info: [eap] EAP/peap
Wed Apr 27 15:09:47 2016 : Info: [eap] processing type peap
Wed Apr 27 15:09:47 2016 : Info: [peap] processing EAP-TLS
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_verify returned 7
Wed Apr 27 15:09:47 2016 : Info: [peap] Done initial handshake
Wed Apr 27 15:09:47 2016 : Info: [peap] eaptls_process returned 7
Wed Apr 27 15:09:47 2016 : Info: [peap] EAPTLS_OK
Wed Apr 27 15:09:47 2016 : Info: [peap] Session established. Decoding tunneled
attributes.
Wed Apr 27 15:09:47 2016 : Info: [peap] Peap state send tlv failure
Wed Apr 27 15:09:47 2016 : Info: [peap] Received EAP-TLV response.
Wed Apr 27 15:09:47 2016 : Info: [peap] The users session was previously
rejected: returning reject (again.)
Wed Apr 27 15:09:47 2016 : Info: [peap] *** This means you need to read the
PREVIOUS messages in the debug output
Wed Apr 27 15:09:47 2016 : Info: [peap] *** to find out the reason why the
user was rejected.
Wed Apr 27 15:09:47 2016 : Info: [peap] *** Look for "reject" or "fail".
Those earlier messages will tell you.
Wed Apr 27 15:09:47 2016 : Info: [peap] *** what went wrong, and how to fix
the problem.
Wed Apr 27 15:09:47 2016 : Info: [eap] Handler failed in EAP/peap
Wed Apr 27 15:09:47 2016 : Info: [eap] Failed in EAP select
Wed Apr 27 15:09:47 2016 : Info: ++[eap] = invalid
Wed Apr 27 15:09:47 2016 : Info: +} # group authenticate = invalid
Wed Apr 27 15:09:47 2016 : Info: Failed to authenticate the user.
Wed Apr 27 15:09:47 2016 : Auth: Login incorrect: [domain\\my_ad_user] (from
client 10.1.10.234 port 79 cli 8c:70:5a:05:81:7c)
Wed Apr 27 15:09:47 2016 : Info: } # server packetfence
Wed Apr 27 15:09:47 2016 : Info: Using Post-Auth-Type REJECT
Wed Apr 27 15:09:47 2016 : Info: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
Wed Apr 27 15:09:47 2016 : Info: +group REJECT {
Wed Apr 27 15:09:47 2016 : Info: ++? if (!EAP-Type || (EAP-Type != EAP-TTLS &&
EAP-Type != PEAP))
Wed Apr 27 15:09:47 2016 : Info: ? Evaluating !(EAP-Type ) -> FALSE
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (EAP-Type != EAP-TTLS ) -> TRUE
Wed Apr 27 15:09:47 2016 : Info: ?? Evaluating (EAP-Type != PEAP) -> FALSE
Wed Apr 27 15:09:47 2016 : Info: ++? if (!EAP-Type || (EAP-Type != EAP-TTLS &&
EAP-Type != PEAP)) -> FALSE
Wed Apr 27 15:09:47 2016 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> domain\\my_ad_user
Wed Apr 27 15:09:47 2016 : Debug: attr_filter: Matched entry DEFAULT at line 11
Wed Apr 27 15:09:47 2016 : Info: ++[attr_filter.access_reject] = updated
Wed Apr 27 15:09:47 2016 : Info: +} # group REJECT = updated
Wed Apr 27 15:09:47 2016 : Info: Delaying reject of request 8 for 1 seconds
Wed Apr 27 15:09:47 2016 : Debug: Going to the next request
Wed Apr 27 15:09:47 2016 : Debug: Waking up in 0.9 seconds.
Wed Apr 27 15:09:48 2016 : Info: Sending delayed reject for request 8
Sending Access-Reject of id 196 to 10.1.10.234 port 33734
EAP-Message = 0x040a0004
Message-Authenticator = 0x00000000000000000000000000000000
Wed Apr 27 15:09:48 2016 : Debug: Waking up in 0.5 seconds.
Wed Apr 27 15:09:49 2016 : Info: Cleaning up request 0 ID 188 with timestamp +8
Wed Apr 27 15:09:49 2016 : Info: Cleaning up request 1 ID 189 with timestamp +8
Wed Apr 27 15:09:49 2016 : Debug: Waking up in 3.0 seconds.
Wed Apr 27 15:09:52 2016 : Info: Cleaning up request 2 ID 190 with timestamp +11
Wed Apr 27 15:09:52 2016 : Info: Cleaning up request 3 ID 191 with timestamp +11
Wed Apr 27 15:09:52 2016 : Info: Cleaning up request 4 ID 192 with timestamp +11
Wed Apr 27 15:09:52 2016 : Info: Cleaning up request 5 ID 193 with timestamp +11
Wed Apr 27 15:09:52 2016 : Info: Cleaning up request 6 ID 194 with timestamp +11
Wed Apr 27 15:09:52 2016 : Info: Cleaning up request 7 ID 195 with timestamp +11
Wed Apr 27 15:09:52 2016 : Debug: Waking up in 1.0 seconds.
Wed Apr 27 15:09:53 2016 : Info: Cleaning up request 8 ID 196 with timestamp +11
Wed Apr 27 15:09:53 2016 : Info: Ready to process requests.
Gábor Barócsi
Network and System Engineer
From: Louis Munro [mailto:[email protected]]
Sent: 2016. április 27. 18:01
To: [email protected]
Subject: Re: [PacketFence-users] 802.1x + SoH issue, please help
On Apr 27, 2016, at 10:01 , BARÓCSI Gábor <[email protected]> wrote:
Hi Louis,
I understand that, but it must work correctly with win7,win8 and win8.1 systems
which have NAP clients.
I know that SoH is not supported by MS in win10 clienOS, but I'm trying to
connect with a 8.1.
Then you need to provide us with a full radius trace for one of those devices
using SoH.
There is not much we can tell from the fact that some variable was undefined.
Regards,
--
Louis Munro
[email protected] :: www.inverse.ca
+1.514.447.4918 x125 :: +1 (866) 353-6153 x125
Inverse inc. :: Leaders behind SOGo (www.sogo.nu) and PacketFence
(www.packetfence.org)
------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z
_______________________________________________
PacketFence-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/packetfence-users
