Hi Fabrice,
Many thanks for the response, appreciate it.
Below is the output from
raddebug -f /usr/local/pf/var/run/radiusd.sock -t 3600
thank you.
(76) Fri Jul 20 10:40:04 2018: Debug: Received Access-Request Id 1
from 10.10.51.169:1812 <http://10.10.51.169:1812> to 10.10.50.233:1812
<http://10.10.50.233:1812> length 119
(76) Fri Jul 20 10:40:04 2018: Debug: User-Name = "pica8"
(76) Fri Jul 20 10:40:04 2018: Debug: NAS-IP-Address = 0.0.0.0
(76) Fri Jul 20 10:40:04 2018: Debug: NAS-Port-Type = Ethernet
(76) Fri Jul 20 10:40:04 2018: Debug: NAS-Port = 20
(76) Fri Jul 20 10:40:04 2018: Debug: Called-Station-Id =
"CC-37-AB-4F-B1-C1"
(76) Fri Jul 20 10:40:04 2018: Debug: Calling-Station-Id =
"18-03-73-62-A6-A4"
(76) Fri Jul 20 10:40:04 2018: Debug: Framed-MTU = 1500
(76) Fri Jul 20 10:40:04 2018: Debug: EAP-Message =
0x02e3000a017069636138
(76) Fri Jul 20 10:40:04 2018: Debug: Message-Authenticator =
0xd5926de557b27889078922ad1c33991d
(76) Fri Jul 20 10:40:04 2018: Debug: # Executing section authorize
from file /usr/local/pf/raddb/sites-enabled/packetfence
(76) Fri Jul 20 10:40:04 2018: Debug: authorize {
(76) Fri Jul 20 10:40:04 2018: Debug: update {
(76) Fri Jul 20 10:40:04 2018: Debug: EXPAND
%{Packet-Src-IP-Address}
(76) Fri Jul 20 10:40:04 2018: Debug: --> 10.10.51.169
(76) Fri Jul 20 10:40:04 2018: Debug: EXPAND %l
(76) Fri Jul 20 10:40:04 2018: Debug: --> 1532054404
(76) Fri Jul 20 10:40:04 2018: Debug: } # update = noop
(76) Fri Jul 20 10:40:04 2018: Debug: policy
packetfence-set-tenant-id {
(76) Fri Jul 20 10:40:04 2018: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(76) Fri Jul 20 10:40:04 2018: Debug: EXPAND
%{%{control:PacketFence-Tenant-Id}:-0}
(76) Fri Jul 20 10:40:04 2018: Debug: --> 0
(76) Fri Jul 20 10:40:04 2018: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE
(76) Fri Jul 20 10:40:04 2018: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(76) Fri Jul 20 10:40:04 2018: Debug: update control {
(76) Fri Jul 20 10:40:04 2018: Debug: EXPAND %{User-Name}
(76) Fri Jul 20 10:40:04 2018: Debug: --> pica8
(76) Fri Jul 20 10:40:04 2018: Debug: SQL-User-Name set to 'pica8'
(76) Fri Jul 20 10:40:04 2018: Debug: Executing select
query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname
= '10.10.51.169'), 0)
(76) Fri Jul 20 10:40:04 2018: Debug: EXPAND %{sql: SELECT
IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
'%{Packet-Src-IP-Address}'), 0)}
(76) Fri Jul 20 10:40:04 2018: Debug: --> 1
(76) Fri Jul 20 10:40:04 2018: Debug: } # update control = noop
(76) Fri Jul 20 10:40:04 2018: Debug: } # if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop
(76) Fri Jul 20 10:40:04 2018: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) {
(76) Fri Jul 20 10:40:04 2018: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: } # policy
packetfence-set-tenant-id = noop
(76) Fri Jul 20 10:40:04 2018: Debug: policy
rewrite_calling_station_id {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
{
(76) Fri Jul 20 10:40:04 2018: Debug: if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
-> TRUE
(76) Fri Jul 20 10:40:04 2018: Debug: if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
{
(76) Fri Jul 20 10:40:04 2018: Debug: update request {
(76) Fri Jul 20 10:40:04 2018: Debug: EXPAND
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(76) Fri Jul 20 10:40:04 2018: Debug: --> 18:03:73:62:a6:a4
(76) Fri Jul 20 10:40:04 2018: Debug: } # update request = noop
(76) Fri Jul 20 10:40:04 2018: Debug: [updated] = updated
(76) Fri Jul 20 10:40:04 2018: Debug: } # if
(&Calling-Station-Id && (&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
= updated
(76) Fri Jul 20 10:40:04 2018: Debug: ... skipping else:
Preceding "if" was taken
(76) Fri Jul 20 10:40:04 2018: Debug: } # policy
rewrite_calling_station_id = updated
(76) Fri Jul 20 10:40:04 2018: Debug: policy
rewrite_called_station_id {
(76) Fri Jul 20 10:40:04 2018: Debug: if ((&Called-Station-Id)
&& (&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
{
(76) Fri Jul 20 10:40:04 2018: Debug: if ((&Called-Station-Id)
&& (&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
-> TRUE
(76) Fri Jul 20 10:40:04 2018: Debug: if ((&Called-Station-Id)
&& (&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
{
(76) Fri Jul 20 10:40:04 2018: Debug: update request {
(76) Fri Jul 20 10:40:04 2018: Debug: EXPAND
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(76) Fri Jul 20 10:40:04 2018: Debug: --> cc:37:ab:4f:b1:c1
(76) Fri Jul 20 10:40:04 2018: Debug: } # update request = noop
(76) Fri Jul 20 10:40:04 2018: Debug: if ("%{8}") {
(76) Fri Jul 20 10:40:04 2018: Debug: EXPAND %{8}
(76) Fri Jul 20 10:40:04 2018: Debug: -->
(76) Fri Jul 20 10:40:04 2018: Debug: if ("%{8}") -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: elsif (
(Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) {
(76) Fri Jul 20 10:40:04 2018: Debug: elsif (
(Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: elsif (Aruba-Essid-Name) {
(76) Fri Jul 20 10:40:04 2018: Debug: elsif
(Aruba-Essid-Name) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: elsif ( (Cisco-AVPair)
&& "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) {
(76) Fri Jul 20 10:40:04 2018: Debug: elsif ( (Cisco-AVPair)
&& "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: [updated] = updated
(76) Fri Jul 20 10:40:04 2018: Debug: } # if
((&Called-Station-Id) && (&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
= updated
(76) Fri Jul 20 10:40:04 2018: Debug: ... skipping else:
Preceding "if" was taken
(76) Fri Jul 20 10:40:04 2018: Debug: } # policy
rewrite_called_station_id = updated
(76) Fri Jul 20 10:40:04 2018: Debug: policy filter_username {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name) {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name) -> TRUE
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name) {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ / /) {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ / /)
-> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~
/@[^@]*@/ ) {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~
/@[^@]*@/ ) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ /\.\./ ) {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ /\.\./
) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/)) {
(76) Fri Jul 20 10:40:04 2018: Debug: if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ /\.$/) {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~
/\.$/) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ /@\./) {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~
/@\./) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: } # if (&User-Name) = updated
(76) Fri Jul 20 10:40:04 2018: Debug: } # policy filter_username =
updated
(76) Fri Jul 20 10:40:04 2018: Debug: policy filter_password {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Password &&
(&User-Password != "%{string:User-Password}")) {
(76) Fri Jul 20 10:40:04 2018: Debug: if (&User-Password &&
(&User-Password != "%{string:User-Password}")) -> FALSE
(76) Fri Jul 20 10:40:04 2018: Debug: } # policy filter_password =
updated
(76) Fri Jul 20 10:40:04 2018: Debug: [preprocess] = ok
(76) Fri Jul 20 10:40:04 2018: Debug: suffix: Checking for suffix
after "@"
(76) Fri Jul 20 10:40:04 2018: Debug: suffix: No '@' in User-Name =
"pica8", skipping NULL due to config.
(76) Fri Jul 20 10:40:04 2018: Debug: [suffix] = noop
(76) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Checking for prefix
before "\"
(76) Fri Jul 20 10:40:04 2018: Debug: ntdomain: No '\' in User-Name =
"pica8", looking up realm NULL
(76) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Found realm "null"
(76) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Adding
Stripped-User-Name = "pica8"
(76) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Adding Realm = "null"
(76) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Authentication realm
is LOCAL
(76) Fri Jul 20 10:40:04 2018: Debug: [ntdomain] = ok
(76) Fri Jul 20 10:40:04 2018: Debug: eap: Peer sent EAP Response
(code 2) ID 227 length 10
(76) Fri Jul 20 10:40:04 2018: Debug: eap: EAP-Identity reply,
returning 'ok' so we can short-circuit the rest of authorize
(76) Fri Jul 20 10:40:04 2018: Debug: [eap] = ok
(76) Fri Jul 20 10:40:04 2018: Debug: } # authorize = ok
(76) Fri Jul 20 10:40:04 2018: Debug: Found Auth-Type = eap
(76) Fri Jul 20 10:40:04 2018: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
(76) Fri Jul 20 10:40:04 2018: Debug: authenticate {
(76) Fri Jul 20 10:40:04 2018: Debug: eap: Peer sent packet with
method EAP Identity (1)
(76) Fri Jul 20 10:40:04 2018: Debug: eap: Calling submodule eap_peap
to process data
(76) Fri Jul 20 10:40:04 2018: Debug: eap_peap: Initiating new EAP-TLS
session
(76) Fri Jul 20 10:40:04 2018: Debug: eap_peap: [eaptls start] = request
(76) Fri Jul 20 10:40:04 2018: Debug: eap: Sending EAP Request (code
1) ID 228 length 6
(76) Fri Jul 20 10:40:04 2018: Debug: eap: EAP session adding
&reply:State = 0x5295783052716193
(76) Fri Jul 20 10:40:04 2018: Debug: [eap] = handled
(76) Fri Jul 20 10:40:04 2018: Debug: } # authenticate = handled
(76) Fri Jul 20 10:40:04 2018: Debug: Using Post-Auth-Type Challenge
(76) Fri Jul 20 10:40:04 2018: Debug: Post-Auth-Type sub-section not
found. Ignoring.
(76) Fri Jul 20 10:40:04 2018: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
(76) Fri Jul 20 10:40:04 2018: Debug: Sent Access-Challenge Id 1 from
10.10.50.233:1812 <http://10.10.50.233:1812> to 10.10.51.169:1812
<http://10.10.51.169:1812> length 0
(76) Fri Jul 20 10:40:04 2018: Debug: EAP-Message = 0x01e400061920
(76) Fri Jul 20 10:40:04 2018: Debug: Message-Authenticator =
0x00000000000000000000000000000000
(76) Fri Jul 20 10:40:04 2018: Debug: State =
0x5295783052716193fc43d749c62f8da2
(76) Fri Jul 20 10:40:04 2018: Debug: Finished request
(77) Fri Jul 20 10:40:04 2018: Debug: Received Access-Request Id 2
from 10.10.51.169:1812 <http://10.10.51.169:1812> to 10.10.50.233:1812
<http://10.10.50.233:1812> length 207
(77) Fri Jul 20 10:40:04 2018: Debug: User-Name = "pica8"
(77) Fri Jul 20 10:40:04 2018: Debug: NAS-IP-Address = 0.0.0.0
(77) Fri Jul 20 10:40:04 2018: Debug: NAS-Port-Type = Ethernet
(77) Fri Jul 20 10:40:04 2018: Debug: NAS-Port = 20
(77) Fri Jul 20 10:40:04 2018: Debug: Called-Station-Id =
"CC-37-AB-4F-B1-C1"
(77) Fri Jul 20 10:40:04 2018: Debug: Calling-Station-Id =
"18-03-73-62-A6-A4"
(77) Fri Jul 20 10:40:04 2018: Debug: Framed-MTU = 1500
(77) Fri Jul 20 10:40:04 2018: Debug: EAP-Message =
0x02e4005019800000004616030100410100003d03015b514acc7f4a7d68bbfa2b2bef3c8e501df47b34046d926ab5d29e5d69d1d9f200001600040005000a000900640062000300060013001200630100
(77) Fri Jul 20 10:40:04 2018: Debug: State =
0x5295783052716193fc43d749c62f8da2
(77) Fri Jul 20 10:40:04 2018: Debug: Message-Authenticator =
0x5e794b5af1ca356d20a0564865e7cae7
(77) Fri Jul 20 10:40:04 2018: Debug: session-state: No cached attributes
(77) Fri Jul 20 10:40:04 2018: Debug: # Executing section authorize
from file /usr/local/pf/raddb/sites-enabled/packetfence
(77) Fri Jul 20 10:40:04 2018: Debug: authorize {
(77) Fri Jul 20 10:40:04 2018: Debug: update {
(77) Fri Jul 20 10:40:04 2018: Debug: EXPAND
%{Packet-Src-IP-Address}
(77) Fri Jul 20 10:40:04 2018: Debug: --> 10.10.51.169
(77) Fri Jul 20 10:40:04 2018: Debug: EXPAND %l
(77) Fri Jul 20 10:40:04 2018: Debug: --> 1532054404
(77) Fri Jul 20 10:40:04 2018: Debug: } # update = noop
(77) Fri Jul 20 10:40:04 2018: Debug: policy
packetfence-set-tenant-id {
(77) Fri Jul 20 10:40:04 2018: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(77) Fri Jul 20 10:40:04 2018: Debug: EXPAND
%{%{control:PacketFence-Tenant-Id}:-0}
(77) Fri Jul 20 10:40:04 2018: Debug: --> 0
(77) Fri Jul 20 10:40:04 2018: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE
(77) Fri Jul 20 10:40:04 2018: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(77) Fri Jul 20 10:40:04 2018: Debug: update control {
(77) Fri Jul 20 10:40:04 2018: Debug: EXPAND %{User-Name}
(77) Fri Jul 20 10:40:04 2018: Debug: --> pica8
(77) Fri Jul 20 10:40:04 2018: Debug: SQL-User-Name set to 'pica8'
(77) Fri Jul 20 10:40:04 2018: Debug: Executing select
query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname
= '10.10.51.169'), 0)
(77) Fri Jul 20 10:40:04 2018: Debug: EXPAND %{sql: SELECT
IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
'%{Packet-Src-IP-Address}'), 0)}
(77) Fri Jul 20 10:40:04 2018: Debug: --> 1
(77) Fri Jul 20 10:40:04 2018: Debug: } # update control = noop
(77) Fri Jul 20 10:40:04 2018: Debug: } # if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop
(77) Fri Jul 20 10:40:04 2018: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: } # policy
packetfence-set-tenant-id = noop
(77) Fri Jul 20 10:40:04 2018: Debug: policy
rewrite_calling_station_id {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
{
(77) Fri Jul 20 10:40:04 2018: Debug: if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
-> TRUE
(77) Fri Jul 20 10:40:04 2018: Debug: if (&Calling-Station-Id &&
(&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
{
(77) Fri Jul 20 10:40:04 2018: Debug: update request {
(77) Fri Jul 20 10:40:04 2018: Debug: EXPAND
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(77) Fri Jul 20 10:40:04 2018: Debug: --> 18:03:73:62:a6:a4
(77) Fri Jul 20 10:40:04 2018: Debug: } # update request = noop
(77) Fri Jul 20 10:40:04 2018: Debug: [updated] = updated
(77) Fri Jul 20 10:40:04 2018: Debug: } # if
(&Calling-Station-Id && (&Calling-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))
= updated
(77) Fri Jul 20 10:40:04 2018: Debug: ... skipping else:
Preceding "if" was taken
(77) Fri Jul 20 10:40:04 2018: Debug: } # policy
rewrite_calling_station_id = updated
(77) Fri Jul 20 10:40:04 2018: Debug: policy
rewrite_called_station_id {
(77) Fri Jul 20 10:40:04 2018: Debug: if ((&Called-Station-Id)
&& (&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
{
(77) Fri Jul 20 10:40:04 2018: Debug: if ((&Called-Station-Id)
&& (&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
-> TRUE
(77) Fri Jul 20 10:40:04 2018: Debug: if ((&Called-Station-Id)
&& (&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
{
(77) Fri Jul 20 10:40:04 2018: Debug: update request {
(77) Fri Jul 20 10:40:04 2018: Debug: EXPAND
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(77) Fri Jul 20 10:40:04 2018: Debug: --> cc:37:ab:4f:b1:c1
(77) Fri Jul 20 10:40:04 2018: Debug: } # update request = noop
(77) Fri Jul 20 10:40:04 2018: Debug: if ("%{8}") {
(77) Fri Jul 20 10:40:04 2018: Debug: EXPAND %{8}
(77) Fri Jul 20 10:40:04 2018: Debug: -->
(77) Fri Jul 20 10:40:04 2018: Debug: if ("%{8}") -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: elsif (
(Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) {
(77) Fri Jul 20 10:40:04 2018: Debug: elsif (
(Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: elsif (Aruba-Essid-Name) {
(77) Fri Jul 20 10:40:04 2018: Debug: elsif
(Aruba-Essid-Name) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: elsif ( (Cisco-AVPair)
&& "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) {
(77) Fri Jul 20 10:40:04 2018: Debug: elsif ( (Cisco-AVPair)
&& "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: [updated] = updated
(77) Fri Jul 20 10:40:04 2018: Debug: } # if
((&Called-Station-Id) && (&Called-Station-Id =~
/^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
= updated
(77) Fri Jul 20 10:40:04 2018: Debug: ... skipping else:
Preceding "if" was taken
(77) Fri Jul 20 10:40:04 2018: Debug: } # policy
rewrite_called_station_id = updated
(77) Fri Jul 20 10:40:04 2018: Debug: policy filter_username {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name) -> TRUE
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ / /) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ / /)
-> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~
/@[^@]*@/ ) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~
/@[^@]*@/ ) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ /\.\./ ) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ /\.\./
) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/)) {
(77) Fri Jul 20 10:40:04 2018: Debug: if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ /\.$/) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~
/\.$/) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~ /@\./) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Name =~
/@\./) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: } # if (&User-Name) = updated
(77) Fri Jul 20 10:40:04 2018: Debug: } # policy filter_username =
updated
(77) Fri Jul 20 10:40:04 2018: Debug: policy filter_password {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Password &&
(&User-Password != "%{string:User-Password}")) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&User-Password &&
(&User-Password != "%{string:User-Password}")) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: } # policy filter_password =
updated
(77) Fri Jul 20 10:40:04 2018: Debug: [preprocess] = ok
(77) Fri Jul 20 10:40:04 2018: Debug: suffix: Checking for suffix
after "@"
(77) Fri Jul 20 10:40:04 2018: Debug: suffix: No '@' in User-Name =
"pica8", skipping NULL due to config.
(77) Fri Jul 20 10:40:04 2018: Debug: [suffix] = noop
(77) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Checking for prefix
before "\"
(77) Fri Jul 20 10:40:04 2018: Debug: ntdomain: No '\' in User-Name =
"pica8", looking up realm NULL
(77) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Found realm "null"
(77) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Adding
Stripped-User-Name = "pica8"
(77) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Adding Realm = "null"
(77) Fri Jul 20 10:40:04 2018: Debug: ntdomain: Authentication realm
is LOCAL
(77) Fri Jul 20 10:40:04 2018: Debug: [ntdomain] = ok
(77) Fri Jul 20 10:40:04 2018: Debug: eap: Peer sent EAP Response
(code 2) ID 228 length 80
(77) Fri Jul 20 10:40:04 2018: Debug: eap: Continuing tunnel setup
(77) Fri Jul 20 10:40:04 2018: Debug: [eap] = ok
(77) Fri Jul 20 10:40:04 2018: Debug: } # authorize = ok
(77) Fri Jul 20 10:40:04 2018: Debug: Found Auth-Type = eap
(77) Fri Jul 20 10:40:04 2018: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
(77) Fri Jul 20 10:40:04 2018: Debug: authenticate {
(77) Fri Jul 20 10:40:04 2018: Debug: eap: Expiring EAP session with
state 0x5295783052716193
(77) Fri Jul 20 10:40:04 2018: Debug: eap: Finished EAP session with
state 0x5295783052716193
(77) Fri Jul 20 10:40:04 2018: Debug: eap: Previous EAP request found
for state 0x5295783052716193, released from the list
(77) Fri Jul 20 10:40:04 2018: Debug: eap: Peer sent packet with
method EAP PEAP (25)
(77) Fri Jul 20 10:40:04 2018: Debug: eap: Calling submodule eap_peap
to process data
(77) Fri Jul 20 10:40:04 2018: Debug: eap_peap: Continuing EAP-TLS
(77) Fri Jul 20 10:40:04 2018: Debug: eap_peap: Peer indicated
complete TLS record size will be 70 bytes
(77) Fri Jul 20 10:40:04 2018: Debug: eap_peap: Got complete TLS
record (70 bytes)
(77) Fri Jul 20 10:40:04 2018: Debug: eap_peap: [eaptls verify] =
length included
(77) Fri Jul 20 10:40:04 2018: Debug: eap_peap: (other): before/accept
initialization
(77) Fri Jul 20 10:40:04 2018: Debug: eap_peap: TLS_accept:
before/accept initialization
(77) Fri Jul 20 10:40:04 2018: ERROR: eap_peap: TLS Alert
write:fatal:handshake failure
(77) Fri Jul 20 10:40:04 2018: ERROR: eap_peap: Failed in __FUNCTION__
(SSL_read):error:1408A0C1:SSL routines:ssl3_get_client_hello:no shared
cipher
(77) Fri Jul 20 10:40:04 2018: ERROR: eap_peap: System call (I/O)
error (-1)
(77) Fri Jul 20 10:40:04 2018: ERROR: eap_peap: TLS receive handshake
failed during operation
(77) Fri Jul 20 10:40:04 2018: ERROR: eap_peap: [eaptls process] = fail
(77) Fri Jul 20 10:40:04 2018: ERROR: eap: Failed continuing EAP PEAP
(25) session. EAP sub-module failed
(77) Fri Jul 20 10:40:04 2018: Debug: eap: Sending EAP Failure (code
4) ID 228 length 4
(77) Fri Jul 20 10:40:04 2018: Debug: eap: Failed in EAP select
(77) Fri Jul 20 10:40:04 2018: Debug: [eap] = invalid
(77) Fri Jul 20 10:40:04 2018: Debug: } # authenticate = invalid
(77) Fri Jul 20 10:40:04 2018: Debug: Failed to authenticate the user
(77) Fri Jul 20 10:40:04 2018: Debug: Using Post-Auth-Type Reject
(77) Fri Jul 20 10:40:04 2018: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
(77) Fri Jul 20 10:40:04 2018: Debug: Post-Auth-Type REJECT {
(77) Fri Jul 20 10:40:04 2018: Debug: update {
(77) Fri Jul 20 10:40:04 2018: Debug: } # update = noop
(77) Fri Jul 20 10:40:04 2018: Debug: if (! EAP-Type || (EAP-Type
!= TTLS && EAP-Type != PEAP) ) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (! EAP-Type || (EAP-Type
!= TTLS && EAP-Type != PEAP) ) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: attr_filter.access_reject:
EXPAND %{User-Name}
(77) Fri Jul 20 10:40:04 2018: Debug: attr_filter.access_reject:
--> pica8
(77) Fri Jul 20 10:40:04 2018: Debug: attr_filter.access_reject:
Matched entry DEFAULT at line 11
(77) Fri Jul 20 10:40:04 2018: Debug: [attr_filter.access_reject] =
updated
(77) Fri Jul 20 10:40:04 2018: Debug:
attr_filter.packetfence_post_auth: EXPAND %{User-Name}
(77) Fri Jul 20 10:40:04 2018: Debug:
attr_filter.packetfence_post_auth: --> pica8
(77) Fri Jul 20 10:40:04 2018: Debug:
attr_filter.packetfence_post_auth: Matched entry DEFAULT at line 10
(77) Fri Jul 20 10:40:04 2018: Debug:
[attr_filter.packetfence_post_auth] = updated
(77) Fri Jul 20 10:40:04 2018: Debug: [eap] = noop
(77) Fri Jul 20 10:40:04 2018: Debug: policy
remove_reply_message_if_eap {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&reply:EAP-Message &&
&reply:Reply-Message) {
(77) Fri Jul 20 10:40:04 2018: Debug: if (&reply:EAP-Message &&
&reply:Reply-Message) -> FALSE
(77) Fri Jul 20 10:40:04 2018: Debug: else {
(77) Fri Jul 20 10:40:04 2018: Debug: [noop] = noop
(77) Fri Jul 20 10:40:04 2018: Debug: } # else = noop
(77) Fri Jul 20 10:40:04 2018: Debug: } # policy
remove_reply_message_if_eap = noop
(77) Fri Jul 20 10:40:04 2018: Debug: linelog: EXPAND
messages.%{%{reply:Packet-Type}:-default}
(77) Fri Jul 20 10:40:04 2018: Debug: linelog: -->
messages.Access-Reject
(77) Fri Jul 20 10:40:04 2018: Debug: linelog: EXPAND
[mac:%{Calling-Station-Id}] Rejected user: %{User-Name}
(77) Fri Jul 20 10:40:04 2018: Debug: linelog: -->
[mac:18:03:73:62:a6:a4] Rejected user: pica8
(77) Fri Jul 20 10:40:04 2018: Debug: [linelog] = ok
(77) Fri Jul 20 10:40:04 2018: Debug: } # Post-Auth-Type REJECT =
updated
(77) Fri Jul 20 10:40:04 2018: Debug: Delaying response for 1.000000
seconds
(75) Fri Jul 20 10:40:05 2018: Debug: Cleaning up request packet ID
204 with timestamp +1162
(77) Fri Jul 20 10:40:05 2018: Debug: Sending delayed response
(77) Fri Jul 20 10:40:05 2018: Debug: Sent Access-Reject Id 2 from
10.10.50.233:1812 <http://10.10.50.233:1812> to 10.10.51.169:1812
<http://10.10.51.169:1812> length 44
(77) Fri Jul 20 10:40:05 2018: Debug: EAP-Message = 0x04e40004
(77) Fri Jul 20 10:40:05 2018: Debug: Message-Authenticator =
0x00000000000000000000000000000000
(76) Fri Jul 20 10:40:09 2018: Debug: Cleaning up request packet ID 1
with timestamp +1166
(77) Fri Jul 20 10:40:09 2018: Debug: Cleaning up request packet ID 2
with timestamp +1166
On Thu, Jul 19, 2018 at 8:26 PM, Fabrice Durand via PacketFence-users
<packetfence-users@lists.sourceforge.net
<mailto:packetfence-users@lists.sourceforge.net>> wrote:
Hello Ali,
you need to paste the raddebug output.
raddebug /usr/local/pf/var/run/radiusd.sock -t 3000
Regards
Fabrice
Le 2018-07-19 à 02:43, Amjad Ali via PacketFence-users a écrit :
Hi everyone,
I have setup a packetfence server in lab environment with just
one switch from edge core 4610-54P running picos NOS from pica8
with 802.1X support.
I then connected a laptop running windows XP with the switch port
but getting "eap: No mutually acceptable types found"
I have installed the latest version of packetfence, password is
plaintext in packetfence configuration.
I've added the user to the users file as stated in installation
guide.
Could this be a problem on laptop i'm connecting with the switch
because all else seems ok to me.
Below are radius messages
User-Name = "john" NAS-IP-Address = 0.0.0.0 NAS-Port-Type =
Ethernet NAS-Port = 20 Calling-Station-Id = "18:03:73:62:a6:a4"
Framed-MTU = 1500 EAP-Message = 0x022600060304 State =
0x002471a8000268f765519fdccd0f8d3a Message-Authenticator =
0x85702b6b9938fee0e421a2b53306356e FreeRADIUS-Client-IP-Address =
10.10.51.169 Called-Station-Id = "cc:37:ab:4f:b1:c1"
Event-Timestamp = "7月 19 2018 13:45:43 CST" Stripped-User-Name
= "john" Realm = "null" EAP-Type = NAK Tmp-String-1 =
"18037362a6a4" Module-Failure-Message = "eap: No mutually
acceptable types found" User-Password = "******" SQL-User-Name =
"john"
Would appreciate if someone could enlighten or point to a
possible solution, thanks.
Ali
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org!http://sdm.link/slashdot
_______________________________________________
PacketFence-users mailing list
PacketFence-users@lists.sourceforge.net
<mailto:PacketFence-users@lists.sourceforge.net>
https://lists.sourceforge.net/lists/listinfo/packetfence-users
<https://lists.sourceforge.net/lists/listinfo/packetfence-users>
--
Fabrice Durand
fdur...@inverse.ca <mailto:fdur...@inverse.ca> :: +1.514.447.4918 (x135)
::www.inverse.ca <http://www.inverse.ca>
Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence
(http://packetfence.org)
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
PacketFence-users mailing list
PacketFence-users@lists.sourceforge.net
<mailto:PacketFence-users@lists.sourceforge.net>
https://lists.sourceforge.net/lists/listinfo/packetfence-users
<https://lists.sourceforge.net/lists/listinfo/packetfence-users>
--
Amjad Ali
