Thank U here u go
root@packetfence ~]# raddebug -f /usr/local/pf/var/run/radiusd.sock -t
3000(703) Thu Oct 15 10:35:30 2020: Debug: Received Status-Server Id 172 from
127.0.0.1:56048 to 127.0.0.1:18121 length 50(703) Thu Oct 15 10:35:30 2020:
Debug: Message-Authenticator = 0x29f77e107025d985d90537b9c9854276(703) Thu
Oct 15 10:35:30 2020: Debug: FreeRADIUS-Statistics-Type = 15(703) Thu Oct 15
10:35:30 2020: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/status(703) Thu Oct 15 10:35:30 2020: Debug:
Autz-Type Status-Server {(703) Thu Oct 15 10:35:30 2020: Debug: [ok] =
ok(703) Thu Oct 15 10:35:30 2020: Debug: } # Autz-Type Status-Server =
ok(703) Thu Oct 15 10:35:30 2020: Debug: Sent Access-Accept Id 172 from
127.0.0.1:18121 to 127.0.0.1:56048 length 0(703) Thu Oct 15 10:35:30 2020:
Debug: FreeRADIUS-Total-Access-Requests = 707(703) Thu Oct 15 10:35:30 2020:
Debug: FreeRADIUS-Total-Access-Accepts = 15(703) Thu Oct 15 10:35:30 2020:
Debug: FreeRADIUS-Total-Access-Rejects = 4(703) Thu Oct 15 10:35:30 2020:
Debug: FreeRADIUS-Total-Access-Challenges = 112(703) Thu Oct 15 10:35:30
2020: Debug: FreeRADIUS-Total-Auth-Responses = 131(703) Thu Oct 15 10:35:30
2020: Debug: FreeRADIUS-Total-Auth-Duplicate-Requests = 3(703) Thu Oct 15
10:35:30 2020: Debug: FreeRADIUS-Total-Auth-Malformed-Requests = 0(703) Thu
Oct 15 10:35:30 2020: Debug: FreeRADIUS-Total-Auth-Invalid-Requests = 0(703)
Thu Oct 15 10:35:30 2020: Debug: FreeRADIUS-Total-Auth-Dropped-Requests =
3(703) Thu Oct 15 10:35:30 2020: Debug: FreeRADIUS-Total-Auth-Unknown-Types =
0(703) Thu Oct 15 10:35:30 2020: Debug: FreeRADIUS-Total-Accounting-Requests
= 0(703) Thu Oct 15 10:35:30 2020: Debug:
FreeRADIUS-Total-Accounting-Responses = 0(703) Thu Oct 15 10:35:30 2020: Debug:
FreeRADIUS-Total-Acct-Duplicate-Requests = 0(703) Thu Oct 15 10:35:30 2020:
Debug: FreeRADIUS-Total-Acct-Malformed-Requests = 0(703) Thu Oct 15 10:35:30
2020: Debug: FreeRADIUS-Total-Acct-Invalid-Requests = 0(703) Thu Oct 15
10:35:30 2020: Debug: FreeRADIUS-Total-Acct-Dropped-Requests = 0(703) Thu Oct
15 10:35:30 2020: Debug: FreeRADIUS-Total-Acct-Unknown-Types = 0(703) Thu Oct
15 10:35:30 2020: Debug: FreeRADIUS-Total-Proxy-Access-Requests = 0(703) Thu
Oct 15 10:35:30 2020: Debug: FreeRADIUS-Total-Proxy-Access-Accepts = 0(703)
Thu Oct 15 10:35:30 2020: Debug: FreeRADIUS-Total-Proxy-Access-Rejects =
0(703) Thu Oct 15 10:35:30 2020: Debug:
FreeRADIUS-Total-Proxy-Access-Challenges = 0(703) Thu Oct 15 10:35:30 2020:
Debug: FreeRADIUS-Total-Proxy-Auth-Responses = 0(703) Thu Oct 15 10:35:30
2020: Debug: FreeRADIUS-Total-Proxy-Auth-Duplicate-Requests = 0(703) Thu Oct
15 10:35:30 2020: Debug: FreeRADIUS-Total-Proxy-Auth-Malformed-Requests =
0(703) Thu Oct 15 10:35:30 2020: Debug:
FreeRADIUS-Total-Proxy-Auth-Invalid-Requests = 0(703) Thu Oct 15 10:35:30 2020:
Debug: FreeRADIUS-Total-Proxy-Auth-Dropped-Requests = 0(703) Thu Oct 15
10:35:30 2020: Debug: FreeRADIUS-Total-Proxy-Auth-Unknown-Types = 0(703) Thu
Oct 15 10:35:30 2020: Debug: FreeRADIUS-Total-Proxy-Accounting-Requests =
0(703) Thu Oct 15 10:35:30 2020: Debug:
FreeRADIUS-Total-Proxy-Accounting-Responses = 0(703) Thu Oct 15 10:35:30 2020:
Debug: FreeRADIUS-Total-Proxy-Acct-Duplicate-Requests = 0(703) Thu Oct 15
10:35:30 2020: Debug: FreeRADIUS-Total-Proxy-Acct-Malformed-Requests = 0(703)
Thu Oct 15 10:35:30 2020: Debug: FreeRADIUS-Total-Proxy-Acct-Invalid-Requests
= 0(703) Thu Oct 15 10:35:30 2020: Debug:
FreeRADIUS-Total-Proxy-Acct-Dropped-Requests = 0(703) Thu Oct 15 10:35:30 2020:
Debug: FreeRADIUS-Total-Proxy-Acct-Unknown-Types = 0(703) Thu Oct 15 10:35:30
2020: Debug: Finished request(704) Thu Oct 15 10:35:31 2020: Debug: Received
Access-Request Id 3 from 10.0.0.229:3495 to 10.0.0.234:1812 length 220(704) Thu
Oct 15 10:35:31 2020: Debug: NAS-Identifier = "damji60E"(704) Thu Oct 15
10:35:31 2020: Debug: User-Name = "b0:35:b5:b9:fb:aa"(704) Thu Oct 15
10:35:31 2020: Debug: User-Password = "b0:35:b5:b9:fb:aa"(704) Thu Oct 15
10:35:31 2020: Debug: NAS-IP-Address = 10.0.0.229(704) Thu Oct 15 10:35:31
2020: Debug: NAS-Port-Type = Virtual(704) Thu Oct 15 10:35:31 2020: Debug:
Called-Station-Id = "08-5B-0E-0E-35-C4:FDTUNNEL"(704) Thu Oct 15 10:35:31 2020:
Debug: Calling-Station-Id = "B0-35-B5-B9-FB-AA"(704) Thu Oct 15 10:35:31
2020: Debug: Fortinet-SSID = "FDTUNNEL"(704) Thu Oct 15 10:35:31 2020: Debug:
Fortinet-AP-Name = "FAP11C3X13002176"(704) Thu Oct 15 10:35:31 2020: Debug:
Acct-Session-Id = "5c191ef8"(704) Thu Oct 15 10:35:31 2020: Debug:
Connect-Info = "web-auth"(704) Thu Oct 15 10:35:31 2020: Debug:
Fortinet-Vdom-Name = "root"(704) Thu Oct 15 10:35:31 2020: Debug:
Service-Type = Login-User(704) Thu Oct 15 10:35:31 2020: Debug: # Executing
section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence(704)
Thu Oct 15 10:35:31 2020: Debug: authorize {(704) Thu Oct 15 10:35:31 2020:
Debug: update {(704) Thu Oct 15 10:35:31 2020: Debug: EXPAND
%{Packet-Src-IP-Address}(704) Thu Oct 15 10:35:31 2020: Debug: -->
10.0.0.229(704) Thu Oct 15 10:35:31 2020: Debug: EXPAND
%{Packet-Dst-IP-Address}(704) Thu Oct 15 10:35:31 2020: Debug: -->
10.0.0.234(704) Thu Oct 15 10:35:31 2020: Debug: EXPAND %l(704) Thu Oct
15 10:35:31 2020: Debug: --> 1602772531(704) Thu Oct 15 10:35:31 2020:
Debug: } # update = noop(704) Thu Oct 15 10:35:31 2020: Debug: policy
packetfence-set-realm-if-machine {(704) Thu Oct 15 10:35:31 2020: Debug:
if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) {(704) Thu Oct 15 10:35:31
2020: Debug: if (User-Name =~ /host\/([a-z0-9_-]*)[\.](.*)/i) ->
FALSE(704) Thu Oct 15 10:35:31 2020: Debug: } # policy
packetfence-set-realm-if-machine = noop(704) Thu Oct 15 10:35:31 2020: Debug:
policy packetfence-balanced-key-policy {(704) Thu Oct 15 10:35:31 2020:
Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~
/^(.*)(.)$/i)) {(704) Thu Oct 15 10:35:31 2020: Debug: if
(&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i)) ->
FALSE(704) Thu Oct 15 10:35:31 2020: Debug: else {(704) Thu Oct 15
10:35:31 2020: Debug: update {(704) Thu Oct 15 10:35:31 2020: Debug:
EXPAND %{md5:%{Calling-Station-Id}%{User-Name}}(704) Thu Oct 15 10:35:31
2020: Debug: --> dc41feae55319aa1564020b73056c100(704) Thu Oct 15
10:35:31 2020: Debug: EXPAND
%{md5:%{Calling-Station-Id}%{User-Name}}(704) Thu Oct 15 10:35:31 2020: Debug:
--> dc41feae55319aa1564020b73056c100(704) Thu Oct 15 10:35:31 2020:
Debug: } # update = noop(704) Thu Oct 15 10:35:31 2020: Debug: }
# else = noop(704) Thu Oct 15 10:35:31 2020: Debug: } # policy
packetfence-balanced-key-policy = noop(704) Thu Oct 15 10:35:31 2020: Debug:
policy packetfence-set-tenant-id {(704) Thu Oct 15 10:35:31 2020: Debug:
if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){(704) Thu Oct 15 10:35:31
2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") ->
FALSE(704) Thu Oct 15 10:35:31 2020: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {(704) Thu Oct 15 10:35:31
2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0}(704) Thu Oct
15 10:35:31 2020: Debug: --> 0(704) Thu Oct 15 10:35:31 2020: Debug:
if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE(704) Thu Oct
15 10:35:31 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" ==
"0") {(704) Thu Oct 15 10:35:31 2020: Debug: update control {(704) Thu
Oct 15 10:35:31 2020: Debug: EXPAND %{User-Name}(704) Thu Oct 15
10:35:31 2020: Debug: --> b0:35:b5:b9:fb:aa(704) Thu Oct 15
10:35:31 2020: Debug: SQL-User-Name set to 'b0:35:b5:b9:fb:aa'(704)
Thu Oct 15 10:35:31 2020: Debug: Executing select query: SELECT
IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.0.0.229'), 0)(704)
Thu Oct 15 10:35:31 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT
tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)}(704) Thu
Oct 15 10:35:31 2020: Debug: --> 0(704) Thu Oct 15 10:35:31 2020:
Debug: } # update control = noop(704) Thu Oct 15 10:35:31 2020: Debug:
} # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop(704) Thu
Oct 15 10:35:31 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 )
{(704) Thu Oct 15 10:35:31 2020: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) -> TRUE(704) Thu Oct 15 10:35:31 2020:
Debug: if ( &control:PacketFence-Tenant-Id == 0 ) {(704) Thu Oct 15
10:35:31 2020: Debug: update control {(704) Thu Oct 15 10:35:31 2020:
Debug: EXPAND %{User-Name}(704) Thu Oct 15 10:35:31 2020: Debug:
--> b0:35:b5:b9:fb:aa(704) Thu Oct 15 10:35:31 2020: Debug:
SQL-User-Name set to 'b0:35:b5:b9:fb:aa'(704) Thu Oct 15 10:35:31 2020: Debug:
Executing select query: SELECT IFNULL((SELECT tenant_id from
radius_nas WHERE start_ip <= INET_ATON('10.0.0.229') and
INET_ATON('10.0.0.229') <= end_ip order by range_length limit 1), 1)(704) Thu
Oct 15 10:35:31 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT
tenant_id from radius_nas WHERE start_ip <= INET_ATON('%{NAS-IP-Address}') and
INET_ATON('%{NAS-IP-Address}') <= end_ip order by range_length limit 1),
1)}(704) Thu Oct 15 10:35:31 2020: Debug: --> 1(704) Thu Oct 15
10:35:31 2020: Debug: } # update control = noop(704) Thu Oct 15
10:35:31 2020: Debug: } # if ( &control:PacketFence-Tenant-Id == 0 ) =
noop(704) Thu Oct 15 10:35:31 2020: Debug: } # policy
packetfence-set-tenant-id = noop(704) Thu Oct 15 10:35:31 2020: Debug:
policy rewrite_calling_station_id {(704) Thu Oct 15 10:35:31 2020: 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))
{(704) Thu Oct 15 10:35:31 2020: 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(704) Thu Oct 15 10:35:31 2020: 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))
{(704) Thu Oct 15 10:35:31 2020: Debug: update request {(704) Thu Oct
15 10:35:31 2020: Debug: EXPAND
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}(704) Thu Oct 15 10:35:31 2020: Debug:
--> b0:35:b5:b9:fb:aa(704) Thu Oct 15 10:35:31 2020: Debug:
} # update request = noop(704) Thu Oct 15 10:35:31 2020: Debug:
[updated] = updated(704) Thu Oct 15 10:35:31 2020: 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(704) Thu Oct 15 10:35:31 2020: Debug: ... skipping else:
Preceding "if" was taken(704) Thu Oct 15 10:35:31 2020: Debug: } # policy
rewrite_calling_station_id = updated(704) Thu Oct 15 10:35:31 2020: Debug:
policy rewrite_called_station_id {(704) Thu Oct 15 10:35:31 2020: 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))
{(704) Thu Oct 15 10:35:31 2020: 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(704) Thu Oct 15 10:35:31 2020: 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))
{(704) Thu Oct 15 10:35:31 2020: Debug: update request {(704) Thu Oct
15 10:35:31 2020: Debug: EXPAND
%{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}(704) Thu Oct 15 10:35:31 2020: Debug:
--> 08:5b:0e:0e:35:c4(704) Thu Oct 15 10:35:31 2020: Debug:
} # update request = noop(704) Thu Oct 15 10:35:31 2020: Debug: if
("%{8}") {(704) Thu Oct 15 10:35:31 2020: Debug: EXPAND %{8}(704) Thu
Oct 15 10:35:31 2020: Debug: --> FDTUNNEL(704) Thu Oct 15 10:35:31
2020: Debug: if ("%{8}") -> TRUE(704) Thu Oct 15 10:35:31 2020: Debug:
if ("%{8}") {(704) Thu Oct 15 10:35:31 2020: Debug: update
request {(704) Thu Oct 15 10:35:31 2020: Debug: EXPAND
%{Called-Station-Id}:%{8}(704) Thu Oct 15 10:35:31 2020: Debug:
--> 08:5b:0e:0e:35:c4:FDTUNNEL(704) Thu Oct 15 10:35:31 2020: Debug:
EXPAND %{8}(704) Thu Oct 15 10:35:31 2020: Debug: -->
FDTUNNEL(704) Thu Oct 15 10:35:31 2020: Debug: } # update request =
noop(704) Thu Oct 15 10:35:31 2020: Debug: } # if ("%{8}") = noop(704)
Thu Oct 15 10:35:31 2020: Debug: ... skipping elsif: Preceding "if" was
taken(704) Thu Oct 15 10:35:31 2020: Debug: ... skipping elsif:
Preceding "if" was taken(704) Thu Oct 15 10:35:31 2020: Debug: ...
skipping elsif: Preceding "if" was taken(704) Thu Oct 15 10:35:31 2020: Debug:
[updated] = updated(704) Thu Oct 15 10:35:31 2020: 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(704) Thu Oct 15 10:35:31 2020: Debug: ... skipping else:
Preceding "if" was taken(704) Thu Oct 15 10:35:31 2020: Debug: } # policy
rewrite_called_station_id = updated(704) Thu Oct 15 10:35:31 2020: Debug:
if ( "%{client:shortname}" =~ /eduroam_tlrs/ ) {(704) Thu Oct 15 10:35:31 2020:
Debug: EXPAND %{client:shortname}(704) Thu Oct 15 10:35:31 2020: Debug:
--> 10.0.0.229/32(704) Thu Oct 15 10:35:31 2020: Debug: if (
"%{client:shortname}" =~ /eduroam_tlrs/ ) -> FALSE(704) Thu Oct 15 10:35:31
2020: Debug: policy filter_username {(704) Thu Oct 15 10:35:31 2020: Debug:
if (&User-Name) {(704) Thu Oct 15 10:35:31 2020: Debug: if
(&User-Name) -> TRUE(704) Thu Oct 15 10:35:31 2020: Debug: if
(&User-Name) {(704) Thu Oct 15 10:35:31 2020: Debug: if (&User-Name =~
/ /) {(704) Thu Oct 15 10:35:31 2020: Debug: if (&User-Name =~ / /) ->
FALSE(704) Thu Oct 15 10:35:31 2020: Debug: if (&User-Name =~ /@[^@]*@/
) {(704) Thu Oct 15 10:35:31 2020: Debug: if (&User-Name =~ /@[^@]*@/ )
-> FALSE(704) Thu Oct 15 10:35:31 2020: Debug: if (&User-Name =~
/\.\./ ) {(704) Thu Oct 15 10:35:31 2020: Debug: if (&User-Name =~
/\.\./ ) -> FALSE(704) Thu Oct 15 10:35:31 2020: Debug: if
((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {(704) Thu Oct 15
10:35:31 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~
/@(.+)\.(.+)$/)) -> FALSE(704) Thu Oct 15 10:35:31 2020: Debug: if
(&User-Name =~ /\.$/) {(704) Thu Oct 15 10:35:31 2020: Debug: if
(&User-Name =~ /\.$/) -> FALSE(704) Thu Oct 15 10:35:31 2020: Debug:
if (&User-Name =~ /@\./) {(704) Thu Oct 15 10:35:31 2020: Debug: if
(&User-Name =~ /@\./) -> FALSE(704) Thu Oct 15 10:35:31 2020: Debug: }
# if (&User-Name) = updated(704) Thu Oct 15 10:35:31 2020: Debug: } #
policy filter_username = updated(704) Thu Oct 15 10:35:31 2020: Debug:
policy filter_password {(704) Thu Oct 15 10:35:31 2020: Debug: if
(&User-Password && (&User-Password != "%{string:User-Password}"))
{(704) Thu Oct 15 10:35:31 2020: Debug: EXPAND
%{string:User-Password}(704) Thu Oct 15 10:35:31 2020: Debug: -->
b0:35:b5:b9:fb:aa(704) Thu Oct 15 10:35:31 2020: Debug: if
(&User-Password && (&User-Password != "%{string:User-Password}")) ->
FALSE(704) Thu Oct 15 10:35:31 2020: Debug: } # policy filter_password =
updated(704) Thu Oct 15 10:35:31 2020: Debug: [preprocess] = ok(704) Thu
Oct 15 10:35:31 2020: Debug: [mschap] = noop(704) Thu Oct 15 10:35:31 2020:
Debug: suffix: Checking for suffix after "@"(704) Thu Oct 15 10:35:31 2020:
Debug: suffix: No '@' in User-Name = "b0:35:b5:b9:fb:aa", skipping NULL due to
config.(704) Thu Oct 15 10:35:31 2020: Debug: [suffix] = noop(704) Thu Oct
15 10:35:31 2020: Debug: ntdomain: Checking for prefix before "\"(704) Thu Oct
15 10:35:31 2020: Debug: ntdomain: No '\' in User-Name = "b0:35:b5:b9:fb:aa",
looking up realm NULL(704) Thu Oct 15 10:35:31 2020: Debug: ntdomain: Found
realm "null"(704) Thu Oct 15 10:35:31 2020: Debug: ntdomain: Adding
Stripped-User-Name = "b0:35:b5:b9:fb:aa"(704) Thu Oct 15 10:35:31 2020: Debug:
ntdomain: Adding Realm = "null"(704) Thu Oct 15 10:35:31 2020: Debug: ntdomain:
Authentication realm is LOCAL(704) Thu Oct 15 10:35:31 2020: Debug:
[ntdomain] = ok(704) Thu Oct 15 10:35:31 2020: Debug: eap: No EAP-Message, not
doing EAP(704) Thu Oct 15 10:35:31 2020: Debug: [eap] = noop(704) Thu Oct
15 10:35:31 2020: Debug: if ( !EAP-Message &&
"%{%{Control:Auth-type}:-No-MS_CHAP}" != "MS-CHAP") {(704) Thu Oct 15 10:35:31
2020: Debug: EXPAND %{%{Control:Auth-type}:-No-MS_CHAP}(704) Thu Oct 15
10:35:31 2020: Debug: --> No-MS_CHAP(704) Thu Oct 15 10:35:31 2020:
Debug: if ( !EAP-Message && "%{%{Control:Auth-type}:-No-MS_CHAP}" !=
"MS-CHAP") -> TRUE(704) Thu Oct 15 10:35:31 2020: Debug: if ( !EAP-Message
&& "%{%{Control:Auth-type}:-No-MS_CHAP}" != "MS-CHAP") {(704) Thu Oct 15
10:35:31 2020: Debug: update {(704) Thu Oct 15 10:35:31 2020: Debug:
} # update = noop(704) Thu Oct 15 10:35:31 2020: Debug: } # if (
!EAP-Message && "%{%{Control:Auth-type}:-No-MS_CHAP}" != "MS-CHAP") =
noop(704) Thu Oct 15 10:35:31 2020: Debug: if (Control:Auth-type ==
"MS-CHAP") {(704) Thu Oct 15 10:35:31 2020: Debug: if (Control:Auth-type ==
"MS-CHAP") -> FALSE(704) Thu Oct 15 10:35:31 2020: Debug: policy
packetfence-eap-mac-policy {(704) Thu Oct 15 10:35:31 2020: Debug: if (
&EAP-Type ) {(704) Thu Oct 15 10:35:31 2020: Debug: if ( &EAP-Type ) ->
FALSE(704) Thu Oct 15 10:35:31 2020: Debug: [noop] = noop(704) Thu Oct 15
10:35:31 2020: Debug: } # policy packetfence-eap-mac-policy = noop(704) Thu
Oct 15 10:35:31 2020: WARNING: pap:
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!(704) Thu Oct 15
10:35:31 2020: WARNING: pap: !!! Ignoring control:User-Password. Update your
!!!(704) Thu Oct 15 10:35:31 2020: WARNING: pap: !!! configuration so that
the "known good" clear text !!!(704) Thu Oct 15 10:35:31 2020: WARNING: pap:
!!! password is in Cleartext-Password and NOT in !!!(704) Thu Oct 15
10:35:31 2020: WARNING: pap: !!! User-Password.
!!!(704) Thu Oct 15 10:35:31 2020: WARNING: pap:
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!(704) Thu Oct 15
10:35:31 2020: WARNING: pap: Auth-Type already set. Not setting to PAP(704)
Thu Oct 15 10:35:31 2020: Debug: [pap] = noop(704) Thu Oct 15 10:35:31
2020: Debug: } # authorize = updated(704) Thu Oct 15 10:35:31 2020: Debug:
Found Auth-Type = Accept(704) Thu Oct 15 10:35:31 2020: Debug: Auth-Type =
Accept, accepting the user(704) Thu Oct 15 10:35:31 2020: Debug: # Executing
section post-auth from file /usr/local/pf/raddb/sites-enabled/packetfence(704)
Thu Oct 15 10:35:31 2020: Debug: post-auth {(704) Thu Oct 15 10:35:31 2020:
Debug: update {(704) Thu Oct 15 10:35:31 2020: Debug: EXPAND
%{Packet-Src-IP-Address}(704) Thu Oct 15 10:35:31 2020: Debug: -->
10.0.0.229(704) Thu Oct 15 10:35:31 2020: Debug: EXPAND
%{Packet-Dst-IP-Address}(704) Thu Oct 15 10:35:31 2020: Debug: -->
10.0.0.234(704) Thu Oct 15 10:35:31 2020: Debug: } # update = noop(704) Thu
Oct 15 10:35:31 2020: Debug: policy packetfence-set-tenant-id {(704) Thu
Oct 15 10:35:31 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address ==
"0.0.0.0"){(704) Thu Oct 15 10:35:31 2020: Debug: if (!NAS-IP-Address ||
NAS-IP-Address == "0.0.0.0") -> FALSE(704) Thu Oct 15 10:35:31 2020: Debug:
if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {(704) Thu Oct 15
10:35:31 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0}(704)
Thu Oct 15 10:35:31 2020: Debug: --> 1(704) Thu Oct 15 10:35:31 2020:
Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") ->
FALSE(704) Thu Oct 15 10:35:31 2020: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) {(704) Thu Oct 15 10:35:31 2020: Debug:
if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE(704) Thu Oct 15
10:35:31 2020: Debug: } # policy packetfence-set-tenant-id = noop(704) Thu
Oct 15 10:35:31 2020: Debug: if
("%{%{control:PacketFence-Proxied-From}:-False}" == "True") {(704) Thu Oct 15
10:35:31 2020: Debug: EXPAND
%{%{control:PacketFence-Proxied-From}:-False}(704) Thu Oct 15 10:35:31 2020:
Debug: --> False(704) Thu Oct 15 10:35:31 2020: Debug: if
("%{%{control:PacketFence-Proxied-From}:-False}" == "True") -> FALSE(704) Thu
Oct 15 10:35:31 2020: Debug: if (! EAP-Type || (EAP-Type != TTLS &&
EAP-Type != PEAP) ) {(704) Thu Oct 15 10:35:31 2020: Debug: if (! EAP-Type
|| (EAP-Type != TTLS && EAP-Type != PEAP) ) -> TRUE(704) Thu Oct 15 10:35:31
2020: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) )
{(704) Thu Oct 15 10:35:31 2020: Debug: rest: Expanding URI components(704) Thu
Oct 15 10:35:31 2020: Debug: rest: EXPAND http://127.0.0.1:7070(704) Thu Oct 15
10:35:31 2020: Debug: rest: --> http://127.0.0.1:7070(704) Thu Oct 15
10:35:31 2020: Debug: rest: EXPAND //radius/rest/authorize(704) Thu Oct 15
10:35:31 2020: Debug: rest: --> //radius/rest/authorize(704) Thu Oct 15
10:35:31 2020: Debug: rest: Sending HTTP POST to
"http://127.0.0.1:7070//radius/rest/authorize";(704) Thu Oct 15 10:35:31 2020:
Debug: rest: Encoding attribute "User-Name"(704) Thu Oct 15 10:35:31 2020:
Debug: rest: Encoding attribute "User-Password"(704) Thu Oct 15 10:35:31 2020:
Debug: rest: Encoding attribute "NAS-IP-Address"(704) Thu Oct 15 10:35:31 2020:
Debug: rest: Encoding attribute "Service-Type"(704) Thu Oct 15 10:35:31 2020:
Debug: rest: Encoding attribute "Called-Station-Id"(704) Thu Oct 15 10:35:31
2020: Debug: rest: Encoding attribute "Calling-Station-Id"(704) Thu Oct 15
10:35:31 2020: Debug: rest: Encoding attribute "NAS-Identifier"(704) Thu Oct 15
10:35:31 2020: Debug: rest: Encoding attribute "NAS-Port-Type"(704) Thu Oct 15
10:35:31 2020: Debug: rest: Encoding attribute "Acct-Session-Id"(704) Thu Oct
15 10:35:31 2020: Debug: rest: Encoding attribute "Event-Timestamp"(704) Thu
Oct 15 10:35:31 2020: Debug: rest: Encoding attribute "Connect-Info"(704) Thu
Oct 15 10:35:31 2020: Debug: rest: Encoding attribute "Fortinet-Vdom-Name"(704)
Thu Oct 15 10:35:31 2020: Debug: rest: Encoding attribute "Fortinet-SSID"(704)
Thu Oct 15 10:35:31 2020: Debug: rest: Encoding attribute
"Fortinet-AP-Name"(704) Thu Oct 15 10:35:31 2020: Debug: rest: Encoding
attribute "Stripped-User-Name"(704) Thu Oct 15 10:35:31 2020: Debug: rest:
Encoding attribute "Realm"(704) Thu Oct 15 10:35:31 2020: Debug: rest: Encoding
attribute "SQL-User-Name"(704) Thu Oct 15 10:35:31 2020: Debug: rest: Encoding
attribute "FreeRADIUS-Client-IP-Address"(704) Thu Oct 15 10:35:31 2020: Debug:
rest: Encoding attribute "Called-Station-SSID"(704) Thu Oct 15 10:35:31 2020:
Debug: rest: Encoding attribute "PacketFence-KeyBalanced"(704) Thu Oct 15
10:35:31 2020: Debug: rest: Encoding attribute "PacketFence-Radius-Ip"(704) Thu
Oct 15 10:35:31 2020: Debug: rest: Processing response header(704) Thu Oct 15
10:35:31 2020: Debug: rest: Status : 100 (Continue)(704) Thu Oct 15 10:35:31
2020: Debug: rest: Continuing...(704) Thu Oct 15 10:35:31 2020: Debug: rest:
Processing response header(704) Thu Oct 15 10:35:31 2020: Debug: rest: Status
: 401 (Unauthorized)(704) Thu Oct 15 10:35:31 2020: Debug: rest: Type :
json (application/json)(704) Thu Oct 15 10:35:31 2020: ERROR: rest: Server
returned:(704) Thu Oct 15 10:35:31 2020: ERROR: rest: {"Reply-Message":"Network
device does not support this mode of
operation","control:PacketFence-Eap-Type":0,"control:PacketFence-Authorization-Status":"allow","control:PacketFence-Mac":"b0:35:b5:b9:fb:aa","control:PacketFence-Request-Time":1602772531,"control:PacketFence-Switch-Ip-Address":"10.0.0.229","control:PacketFence-IfIndex":"external","control:PacketFence-UserName":"b0:35:b5:b9:fb:aa","control:PacketFence-Connection-Type":"CLI-Access","control:PacketFence-Switch-Id":"10.0.0.229","control:PacketFence-Switch-Mac":"08:5b:0e:0e:35:c4"}(704)
Thu Oct 15 10:35:31 2020: Debug: [rest] = invalid(704) Thu Oct 15
10:35:31 2020: Debug: } # if (! EAP-Type || (EAP-Type != TTLS && EAP-Type
!= PEAP) ) = invalid(704) Thu Oct 15 10:35:31 2020: Debug: } # post-auth =
invalid(704) Thu Oct 15 10:35:31 2020: Debug: Using Post-Auth-Type Reject(704)
Thu Oct 15 10:35:31 2020: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence(704) Thu Oct 15 10:35:31 2020:
Debug: Post-Auth-Type REJECT {(704) Thu Oct 15 10:35:31 2020: Debug:
policy packetfence-set-tenant-id {(704) Thu Oct 15 10:35:31 2020: Debug:
if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){(704) Thu Oct 15 10:35:31
2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") ->
FALSE(704) Thu Oct 15 10:35:31 2020: Debug: if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {(704) Thu Oct 15 10:35:31
2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0}(704) Thu Oct
15 10:35:31 2020: Debug: --> 1(704) Thu Oct 15 10:35:31 2020: Debug:
if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> FALSE(704) Thu
Oct 15 10:35:31 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 )
{(704) Thu Oct 15 10:35:31 2020: Debug: if (
&control:PacketFence-Tenant-Id == 0 ) -> FALSE(704) Thu Oct 15 10:35:31 2020:
Debug: } # policy packetfence-set-tenant-id = noop(704) Thu Oct 15 10:35:31
2020: Debug: update {(704) Thu Oct 15 10:35:31 2020: Debug: } # update
= noop(704) Thu Oct 15 10:35:31 2020: Debug: if (! EAP-Type || (EAP-Type !=
TTLS && EAP-Type != PEAP) ) {(704) Thu Oct 15 10:35:31 2020: Debug: if (!
EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) -> TRUE(704) Thu Oct 15
10:35:31 2020: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type !=
PEAP) ) {(704) Thu Oct 15 10:35:31 2020: Debug: policy
packetfence-audit-log-reject {(704) Thu Oct 15 10:35:31 2020: Debug: if
(&User-Name && (&User-Name == "dummy")) {(704) Thu Oct 15 10:35:31 2020: Debug:
if (&User-Name && (&User-Name == "dummy")) -> FALSE(704) Thu Oct 15
10:35:31 2020: Debug: else {(704) Thu Oct 15 10:35:31 2020: Debug:
policy request-timing {(704) Thu Oct 15 10:35:31 2020: Debug:
if ("%{%{control:PacketFence-Request-Time}:-0}" != 0) {(704) Thu Oct 15
10:35:31 2020: Debug: EXPAND
%{%{control:PacketFence-Request-Time}:-0}(704) Thu Oct 15 10:35:31 2020: Debug:
--> 0(704) Thu Oct 15 10:35:31 2020: Debug: if
("%{%{control:PacketFence-Request-Time}:-0}" != 0) -> FALSE(704) Thu Oct 15
10:35:31 2020: Debug: } # policy request-timing = noop(704) Thu Oct
15 10:35:31 2020: Debug: sql_reject: EXPAND type.reject.query(704) Thu Oct 15
10:35:31 2020: Debug: sql_reject: --> type.reject.query(704) Thu Oct 15
10:35:31 2020: Debug: sql_reject: Using query template 'query'(704) Thu Oct 15
10:35:31 2020: Debug: sql_reject: EXPAND %{User-Name}(704) Thu Oct 15 10:35:31
2020: Debug: sql_reject: --> b0:35:b5:b9:fb:aa(704) Thu Oct 15 10:35:31
2020: Debug: sql_reject: SQL-User-Name set to 'b0:35:b5:b9:fb:aa'
On Friday, October 16, 2020, 01:43:44 PM EDT, Ludovic Zammit
<lzam...@inverse.ca> wrote:
Hello,
Yes please, could you send the output of the command:
raddebug -f /usr/local/pf/var/run/radiusd.sock -t 3600 | tee raddebug.log
Thanks,
Ludovic Zammit
lzam...@inverse.ca :: +1.514.447.4918 (x145) :: www.inverse.ca
Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence
(http://packetfence.org)
On Oct 15, 2020, at 11:23 AM, rahim damji via PacketFence-users
<packetfence-users@lists.sourceforge.net> wrote:
I can post my debug if needed
Thanks
Rahim_______________________________________________
PacketFence-users mailing list
PacketFence-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/packetfence-users
_______________________________________________
PacketFence-users mailing list
PacketFence-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/packetfence-users
