Thanks Fabrice

raddebug output:

(727) Mon Oct 26 15:54:22 2020: Debug: Received Access-Request Id 132 from
X.X.X.X:55645 to X.X.X.X:1812 length 191
(727) Mon Oct 26 15:54:22 2020: Debug:   Service-Type = Framed-User
(727) Mon Oct 26 15:54:22 2020: Debug:   Framed-Protocol = PPP
(727) Mon Oct 26 15:54:22 2020: Debug:   NAS-Port = 39
(727) Mon Oct 26 15:54:22 2020: Debug:   NAS-Port-Type = Virtual
(727) Mon Oct 26 15:54:22 2020: Debug:   User-Name = "coyo"
(727) Mon Oct 26 15:54:22 2020: Debug:   Calling-Station-Id = "X.X.X.X"
(727) Mon Oct 26 15:54:22 2020: Debug:   Called-Station-Id = "X.X.X.X"
(727) Mon Oct 26 15:54:22 2020: Debug:   Acct-Session-Id = "81d00cdf"
(727) Mon Oct 26 15:54:22 2020: Debug:   MS-CHAP-Challenge =
0xebf6d832753d4fdf8383548a74da2637
(727) Mon Oct 26 15:54:22 2020: Debug:   MS-CHAP2-Response =
0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5
(727) Mon Oct 26 15:54:22 2020: Debug:   NAS-Identifier = "MK-IBERA2"
(727) Mon Oct 26 15:54:22 2020: Debug:   NAS-IP-Address = X.X.X.X
(727) Mon Oct 26 15:54:22 2020: Debug: # Executing section authorize from
file /usr/local/pf/raddb/sites-enabled/packetfence
(727) Mon Oct 26 15:54:22 2020: Debug:   authorize {
(727) Mon Oct 26 15:54:22 2020: Debug:     policy
packetfence-nas-ip-address {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (!NAS-IP-Address ||
NAS-IP-Address == "0.0.0.0"){
(727) Mon Oct 26 15:54:22 2020: Debug:       if (!NAS-IP-Address ||
NAS-IP-Address == "0.0.0.0") -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
packetfence-nas-ip-address = notfound
(727) Mon Oct 26 15:54:22 2020: Debug:     update {
(727) Mon Oct 26 15:54:22 2020: Debug:       EXPAND %{Packet-Src-IP-Address}
(727) Mon Oct 26 15:54:22 2020: Debug:          --> X.X.X.X
(727) Mon Oct 26 15:54:22 2020: Debug:       EXPAND %{Packet-Dst-IP-Address}
(727) Mon Oct 26 15:54:22 2020: Debug:          --> X.X.X.X
(727) Mon Oct 26 15:54:22 2020: Debug:       EXPAND %l
(727) Mon Oct 26 15:54:22 2020: Debug:          --> 1603738462
(727) Mon Oct 26 15:54:22 2020: Debug:     } # update = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     policy
packetfence-set-realm-if-machine {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (User-Name =~
/host\/([a-z0-9_-]*)[\.](.*)/i) {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (User-Name =~
/host\/([a-z0-9_-]*)[\.](.*)/i)  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
packetfence-set-realm-if-machine = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     policy
packetfence-balanced-key-policy {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (&PacketFence-KeyBalanced
&& (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i)) {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (&PacketFence-KeyBalanced
&& (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i))  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       else {
(727) Mon Oct 26 15:54:22 2020: Debug:         update {
(727) Mon Oct 26 15:54:22 2020: Debug:           EXPAND
%{md5:%{Calling-Station-Id}%{User-Name}}
(727) Mon Oct 26 15:54:22 2020: Debug:              -->
865fdf018805bc0bc5fbb22eaa6b0a60
(727) Mon Oct 26 15:54:22 2020: Debug:           EXPAND
%{md5:%{Calling-Station-Id}%{User-Name}}
(727) Mon Oct 26 15:54:22 2020: Debug:              -->
865fdf018805bc0bc5fbb22eaa6b0a60
(727) Mon Oct 26 15:54:22 2020: Debug:         } # update = noop
(727) Mon Oct 26 15:54:22 2020: Debug:       } # else = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
packetfence-balanced-key-policy = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     policy packetfence-set-tenant-id
{
(727) Mon Oct 26 15:54:22 2020: Debug:       if (!NAS-IP-Address ||
NAS-IP-Address == "0.0.0.0"){
(727) Mon Oct 26 15:54:22 2020: Debug:       if (!NAS-IP-Address ||
NAS-IP-Address == "0.0.0.0") -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(727) Mon Oct 26 15:54:22 2020: Debug:       EXPAND
%{%{control:PacketFence-Tenant-Id}:-0}
(727) Mon Oct 26 15:54:22 2020: Debug:          --> 0
(727) Mon Oct 26 15:54:22 2020: Debug:       if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  -> TRUE
(727) Mon Oct 26 15:54:22 2020: Debug:       if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  {
(727) Mon Oct 26 15:54:22 2020: Debug:         update control {
(727) Mon Oct 26 15:54:22 2020: Debug:           EXPAND %{User-Name}
(727) Mon Oct 26 15:54:22 2020: Debug:              --> coyo
(727) Mon Oct 26 15:54:22 2020: Debug:           SQL-User-Name set to 'coyo'
(727) Mon Oct 26 15:54:22 2020: Debug:           Executing select query:
 SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
'X.X.X.X'), 0)
(727) Mon Oct 26 15:54:22 2020: Debug:           EXPAND %{sql: SELECT
IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
'%{NAS-IP-Address}'), 0)}
(727) Mon Oct 26 15:54:22 2020: Debug:              --> 1
(727) Mon Oct 26 15:54:22 2020: Debug:         } # update control = noop
(727) Mon Oct 26 15:54:22 2020: Debug:       } # if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  = noop
(727) Mon Oct 26 15:54:22 2020: Debug:       if (
&control:PacketFence-Tenant-Id == 0 ) {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (
&control:PacketFence-Tenant-Id == 0 )  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
packetfence-set-tenant-id = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     policy
rewrite_calling_station_id {
(727) Mon Oct 26 15:54:22 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))
{
(727) Mon Oct 26 15:54:22 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))
 -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       else {
(727) Mon Oct 26 15:54:22 2020: Debug:         [noop] = noop
(727) Mon Oct 26 15:54:22 2020: Debug:       } # else = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
rewrite_calling_station_id = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     policy rewrite_called_station_id
{
(727) Mon Oct 26 15:54:22 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))
{
(727) Mon Oct 26 15:54:22 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))
 -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       else {
(727) Mon Oct 26 15:54:22 2020: Debug:         [noop] = noop
(727) Mon Oct 26 15:54:22 2020: Debug:       } # else = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
rewrite_called_station_id = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     if ( "%{client:shortname}" =~
/eduroam_tlrs/ ) {
(727) Mon Oct 26 15:54:22 2020: Debug:     EXPAND %{client:shortname}
(727) Mon Oct 26 15:54:22 2020: Debug:        --> X.X.X.X/32
(727) Mon Oct 26 15:54:22 2020: Debug:     if ( "%{client:shortname}" =~
/eduroam_tlrs/ )  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:     policy filter_username {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (&User-Name) {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (&User-Name)  -> TRUE
(727) Mon Oct 26 15:54:22 2020: Debug:       if (&User-Name)  {
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ / /) {
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ / /)  ->
FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ /@[^@]*@/
) {
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ /@[^@]*@/
)  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ /\.\./ ) {
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ /\.\./ )
 -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:         if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/))  {
(727) Mon Oct 26 15:54:22 2020: Debug:         if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ /\.$/)  {
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ /\.$/)
-> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ /@\./)  {
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name =~ /@\./)
-> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       } # if (&User-Name)  = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy filter_username = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     policy filter_password {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (&User-Password &&
(&User-Password != "%{string:User-Password}")) {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (&User-Password &&
(&User-Password != "%{string:User-Password}"))  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy filter_password = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     [preprocess] = ok
(727) Mon Oct 26 15:54:22 2020: Debug: mschap: Found MS-CHAP attributes.
Setting 'Auth-Type  = mschap'
(727) Mon Oct 26 15:54:22 2020: Debug:     [mschap] = ok
(727) Mon Oct 26 15:54:22 2020: Debug: suffix: Checking for suffix after "@"
(727) Mon Oct 26 15:54:22 2020: Debug: suffix: No '@' in User-Name =
"coyo", skipping NULL due to config.
(727) Mon Oct 26 15:54:22 2020: Debug:     [suffix] = noop
(727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Checking for prefix before
"\"
(727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: No '\' in User-Name =
"coyo", looking up realm NULL
(727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Found realm "null"
(727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Adding Stripped-User-Name
= "coyo"
(727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Adding Realm = "null"
(727) Mon Oct 26 15:54:22 2020: Debug: ntdomain: Authentication realm is
LOCAL
(727) Mon Oct 26 15:54:22 2020: Debug:     [ntdomain] = ok
(727) Mon Oct 26 15:54:22 2020: Debug:     if (Realm =~ /default/) {
(727) Mon Oct 26 15:54:22 2020: Debug:     if (Realm =~ /default/)  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:     elsif (Realm =~ /local/) {
(727) Mon Oct 26 15:54:22 2020: Debug:     elsif (Realm =~ /local/)  ->
FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:     elsif (Realm =~ /null/) {
(727) Mon Oct 26 15:54:22 2020: Debug:     elsif (Realm =~ /null/)  -> TRUE
(727) Mon Oct 26 15:54:22 2020: Debug:     elsif (Realm =~ /null/)  {
(727) Mon Oct 26 15:54:22 2020: Debug: PEAP: No EAP-Message, not doing EAP
(727) Mon Oct 26 15:54:22 2020: Debug:       [PEAP] = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     } # elsif (Realm =~ /null/)  =
noop
(727) Mon Oct 26 15:54:22 2020: Debug:     ... skipping else: Preceding
"if" was taken
(727) Mon Oct 26 15:54:22 2020: Debug:     if ( !EAP-Message &&
"%{%{Control:Auth-type}:-No-MS_CHAP}" != "MS-CHAP") {
(727) Mon Oct 26 15:54:22 2020: Debug:     EXPAND
%{%{Control:Auth-type}:-No-MS_CHAP}
(727) Mon Oct 26 15:54:22 2020: Debug:        --> MS-CHAP
(727) Mon Oct 26 15:54:22 2020: Debug:     if ( !EAP-Message &&
"%{%{Control:Auth-type}:-No-MS_CHAP}" != "MS-CHAP")  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:     if (Control:Auth-type ==
"MS-CHAP") {
(727) Mon Oct 26 15:54:22 2020: Debug:     if (Control:Auth-type ==
"MS-CHAP")  -> TRUE
(727) Mon Oct 26 15:54:22 2020: Debug:     if (Control:Auth-type ==
"MS-CHAP")  {
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'User-Name'} = &request:User-Name -> 'coyo'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'NAS-IP-Address'} = &request:NAS-IP-Address -> 'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'NAS-Port'} = &request:NAS-Port -> '39'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'Service-Type'} = &request:Service-Type -> 'Framed-User'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'Framed-Protocol'} = &request:Framed-Protocol -> 'PPP'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'Called-Station-Id'} = &request:Called-Station-Id -> 'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'Calling-Station-Id'} = &request:Calling-Station-Id ->
'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'NAS-Identifier'} = &request:NAS-Identifier -> 'MK-IBERA2'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'NAS-Port-Type'} = &request:NAS-Port-Type -> 'Virtual'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'Acct-Session-Id'} = &request:Acct-Session-Id -> '81d00cdf'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'Event-Timestamp'} = &request:Event-Timestamp -> 'Oct 26 2020
15:54:22 -03'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'MS-CHAP-Challenge'} = &request:MS-CHAP-Challenge ->
'0xebf6d832753d4fdf8383548a74da2637'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'MS-CHAP2-Response'} = &request:MS-CHAP2-Response ->
'0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'Stripped-User-Name'} = &request:Stripped-User-Name -> 'coyo'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'Realm'} = &request:Realm -> 'null'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'SQL-User-Name'} = &request:SQL-User-Name -> 'coyo'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'FreeRADIUS-Client-IP-Address'} =
&request:FreeRADIUS-Client-IP-Address -> 'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'PacketFence-KeyBalanced'} = &request:PacketFence-KeyBalanced
-> '865fdf018805bc0bc5fbb22eaa6b0a60'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_REQUEST{'PacketFence-Radius-Ip'} = &request:PacketFence-Radius-Ip ->
'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'Auth-Type'} = &control:Auth-Type -> 'MS-CHAP'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'Load-Balance-Key'} = &control:Load-Balance-Key ->
'865fdf018805bc0bc5fbb22eaa6b0a60'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'Tmp-Integer-0'} = &control:Tmp-Integer-0 -> '1603738462'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'PacketFence-RPC-Server'} = &control:PacketFence-RPC-Server ->
'127.0.0.1'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'PacketFence-RPC-Port'} = &control:PacketFence-RPC-Port -> '7070'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'PacketFence-RPC-User'} = &control:PacketFence-RPC-User -> ''
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'PacketFence-RPC-Pass'} = &control:PacketFence-RPC-Pass -> ''''
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'PacketFence-RPC-Proto'} = &control:PacketFence-RPC-Proto ->
'http'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'PacketFence-Request-Time'} = &control:PacketFence-Request-Time
-> '0'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CHECK{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id -> '1'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'Auth-Type'} = &control:Auth-Type -> 'MS-CHAP'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'Load-Balance-Key'} = &control:Load-Balance-Key ->
'865fdf018805bc0bc5fbb22eaa6b0a60'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'Tmp-Integer-0'} = &control:Tmp-Integer-0 -> '1603738462'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'PacketFence-RPC-Server'} = &control:PacketFence-RPC-Server ->
'127.0.0.1'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'PacketFence-RPC-Port'} = &control:PacketFence-RPC-Port ->
'7070'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'PacketFence-RPC-User'} = &control:PacketFence-RPC-User -> ''
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'PacketFence-RPC-Pass'} = &control:PacketFence-RPC-Pass -> ''''
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'PacketFence-RPC-Proto'} = &control:PacketFence-RPC-Proto ->
'http'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'PacketFence-Request-Time'} = &control:PacketFence-Request-Time
-> '0'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
$RAD_CONFIG{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id -> '1'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:NAS-Port-Type = $RAD_REQUEST{'NAS-Port-Type'} -> 'Virtual'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:Acct-Session-Id = $RAD_REQUEST{'Acct-Session-Id'} -> '81d00cdf'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:PacketFence-Radius-Ip = $RAD_REQUEST{'PacketFence-Radius-Ip'} ->
'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:Service-Type = $RAD_REQUEST{'Service-Type'} -> 'Framed-User'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:Called-Station-Id = $RAD_REQUEST{'Called-Station-Id'} -> 'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:Realm = $RAD_REQUEST{'Realm'} -> 'null'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:NAS-IP-Address = $RAD_REQUEST{'NAS-IP-Address'} -> 'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:SQL-User-Name = $RAD_REQUEST{'SQL-User-Name'} -> 'coyo'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:PacketFence-NTLMv2-Only = $RAD_REQUEST{'PacketFence-NTLMv2-Only'}
-> ''
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:Calling-Station-Id = $RAD_REQUEST{'Calling-Station-Id'} ->
'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:PacketFence-KeyBalanced = $RAD_REQUEST{'PacketFence-KeyBalanced'}
-> '865fdf018805bc0bc5fbb22eaa6b0a60'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:FreeRADIUS-Client-IP-Address =
$RAD_REQUEST{'FreeRADIUS-Client-IP-Address'} -> 'X.X.X.X'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:MS-CHAP-Challenge = $RAD_REQUEST{'MS-CHAP-Challenge'} ->
'0xebf6d832753d4fdf8383548a74da2637'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:Framed-Protocol = $RAD_REQUEST{'Framed-Protocol'} -> 'PPP'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:User-Name = $RAD_REQUEST{'User-Name'} -> 'coyo'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:NAS-Identifier = $RAD_REQUEST{'NAS-Identifier'} -> 'MK-IBERA2'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:Event-Timestamp = $RAD_REQUEST{'Event-Timestamp'} -> 'Oct 26 2020
15:54:22 -03'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:MS-CHAP2-Response = $RAD_REQUEST{'MS-CHAP2-Response'} ->
'0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:NAS-Port = $RAD_REQUEST{'NAS-Port'} -> '39'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&request:Stripped-User-Name = $RAD_REQUEST{'Stripped-User-Name'} -> 'coyo'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:Load-Balance-Key = $RAD_CHECK{'Load-Balance-Key'} ->
'865fdf018805bc0bc5fbb22eaa6b0a60'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:PacketFence-RPC-Server = $RAD_CHECK{'PacketFence-RPC-Server'} ->
'127.0.0.1'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:PacketFence-Tenant-Id = $RAD_CHECK{'PacketFence-Tenant-Id'} -> '1'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:PacketFence-RPC-User = $RAD_CHECK{'PacketFence-RPC-User'} -> ''
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:PacketFence-Request-Time = $RAD_CHECK{'PacketFence-Request-Time'}
-> '0'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:Auth-Type = $RAD_CHECK{'Auth-Type'} -> 'MS-CHAP'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:PacketFence-RPC-Pass = $RAD_CHECK{'PacketFence-RPC-Pass'} -> ''''
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:Tmp-Integer-0 = $RAD_CHECK{'Tmp-Integer-0'} -> '1603738462'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:PacketFence-RPC-Proto = $RAD_CHECK{'PacketFence-RPC-Proto'} ->
'http'
(727) Mon Oct 26 15:54:22 2020: Debug: packetfence-multi-domain:
&control:PacketFence-RPC-Port = $RAD_CHECK{'PacketFence-RPC-Port'} -> '7070'
(727) Mon Oct 26 15:54:22 2020: Debug:       [packetfence-multi-domain] =
updated
(727) Mon Oct 26 15:54:22 2020: Debug:     } # if (Control:Auth-type ==
"MS-CHAP")  = updated
(727) Mon Oct 26 15:54:22 2020: Debug:     policy
packetfence-eap-mac-policy {
(727) Mon Oct 26 15:54:22 2020: Debug:       if ( &EAP-Type ) {
(727) Mon Oct 26 15:54:22 2020: Debug:       if ( &EAP-Type )  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       [noop] = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
packetfence-eap-mac-policy = noop
(727) Mon Oct 26 15:54:22 2020: WARNING: pap:
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
(727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!! Ignoring
control:User-Password.  Update your        !!!
(727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!! configuration so that the
"known good" clear text !!!
(727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!! password is in
Cleartext-Password and NOT in        !!!
(727) Mon Oct 26 15:54:22 2020: WARNING: pap: !!! User-Password.
                           !!!
(727) Mon Oct 26 15:54:22 2020: WARNING: pap:
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
(727) Mon Oct 26 15:54:22 2020: Debug:     [pap] = noop
(727) Mon Oct 26 15:54:22 2020: Debug:   } # authorize = updated
(727) Mon Oct 26 15:54:22 2020: Debug: Found Auth-Type = MS-CHAP
(727) Mon Oct 26 15:54:22 2020: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
(727) Mon Oct 26 15:54:22 2020: Debug:   Auth-Type MS-CHAP {
(727) Mon Oct 26 15:54:22 2020: Debug:     policy
packetfence-mschap-authenticate {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (PacketFence-Domain) {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (PacketFence-Domain)  ->
FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       else {
(727) Mon Oct 26 15:54:22 2020: Debug:         if ( "%{User-Name}" =~
/^host\/.*/) {
(727) Mon Oct 26 15:54:22 2020: Debug:         EXPAND %{User-Name}
(727) Mon Oct 26 15:54:22 2020: Debug:            --> coyo
(727) Mon Oct 26 15:54:22 2020: Debug:         if ( "%{User-Name}" =~
/^host\/.*/)  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:         else {
(727) Mon Oct 26 15:54:22 2020: Debug: mschap: Creating challenge hash with
username: coyo
(727) Mon Oct 26 15:54:22 2020: Debug: mschap: Client is using MS-CHAPv2
(727) Mon Oct 26 15:54:22 2020: Debug: mschap: Executing:
/usr/local/pf/bin/ntlm_auth_wrapper -p 8125 --          --request-nt-key
 
--username=%{%{control:AD-Samaccountname}:-%{%{Stripped-User-Name}:-%{mschap:User-Name:-None}}}
--challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}:
(727) Mon Oct 26 15:54:22 2020: Debug: mschap: EXPAND
--username=%{%{control:AD-Samaccountname}:-%{%{Stripped-User-Name}:-%{mschap:User-Name:-None}}}
(727) Mon Oct 26 15:54:22 2020: Debug: mschap:    --> --username=coyo
(727) Mon Oct 26 15:54:22 2020: Debug: mschap: Creating challenge hash with
username: coyo
(727) Mon Oct 26 15:54:22 2020: Debug: mschap: EXPAND
--challenge=%{mschap:Challenge:-00}
(727) Mon Oct 26 15:54:22 2020: Debug: mschap:    -->
--challenge=1f4bcfae02f18a60
(727) Mon Oct 26 15:54:22 2020: Debug: mschap: EXPAND
--nt-response=%{mschap:NT-Response:-00}
(727) Mon Oct 26 15:54:22 2020: Debug: mschap:    -->
--nt-response=b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5
(727) Mon Oct 26 15:54:22 2020: ERROR: mschap: Program returned code (1)
and output 'Reading winbind reply failed! (0xc0000001)'
(727) Mon Oct 26 15:54:22 2020: ERROR: mschap: Reading winbind reply
failed! (0xc0000001)
(727) Mon Oct 26 15:54:22 2020: Debug: mschap: Authentication failed
(727) Mon Oct 26 15:54:22 2020: Debug:           [mschap] = fail
(727) Mon Oct 26 15:54:22 2020: Debug:         } # else = fail
(727) Mon Oct 26 15:54:22 2020: Debug:       } # else = fail
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
packetfence-mschap-authenticate = fail
(727) Mon Oct 26 15:54:22 2020: Debug:   } # Auth-Type MS-CHAP = fail
(727) Mon Oct 26 15:54:22 2020: Debug: Failed to authenticate the user
(727) Mon Oct 26 15:54:22 2020: Debug: Using Post-Auth-Type Reject
(727) Mon Oct 26 15:54:22 2020: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/packetfence
(727) Mon Oct 26 15:54:22 2020: Debug:   Post-Auth-Type REJECT {
(727) Mon Oct 26 15:54:22 2020: Debug:     policy packetfence-set-tenant-id
{
(727) Mon Oct 26 15:54:22 2020: Debug:       if (!NAS-IP-Address ||
NAS-IP-Address == "0.0.0.0"){
(727) Mon Oct 26 15:54:22 2020: Debug:       if (!NAS-IP-Address ||
NAS-IP-Address == "0.0.0.0") -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
(727) Mon Oct 26 15:54:22 2020: Debug:       EXPAND
%{%{control:PacketFence-Tenant-Id}:-0}
(727) Mon Oct 26 15:54:22 2020: Debug:          --> 1
(727) Mon Oct 26 15:54:22 2020: Debug:       if (
"%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       if (
&control:PacketFence-Tenant-Id == 0 ) {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (
&control:PacketFence-Tenant-Id == 0 )  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
packetfence-set-tenant-id = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     update {
(727) Mon Oct 26 15:54:22 2020: Debug:     } # update = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     if (! EAP-Type || (EAP-Type !=
TTLS  && EAP-Type != PEAP) ) {
(727) Mon Oct 26 15:54:22 2020: Debug:     if (! EAP-Type || (EAP-Type !=
TTLS  && EAP-Type != PEAP) )  -> TRUE
(727) Mon Oct 26 15:54:22 2020: Debug:     if (! EAP-Type || (EAP-Type !=
TTLS  && EAP-Type != PEAP) )  {
(727) Mon Oct 26 15:54:22 2020: Debug:       policy
packetfence-audit-log-reject {
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name &&
(&User-Name == "dummy")) {
(727) Mon Oct 26 15:54:22 2020: Debug:         if (&User-Name &&
(&User-Name == "dummy"))  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:         else {
(727) Mon Oct 26 15:54:22 2020: Debug:           policy request-timing {
(727) Mon Oct 26 15:54:22 2020: Debug:             if
("%{%{control:PacketFence-Request-Time}:-0}" != 0) {
(727) Mon Oct 26 15:54:22 2020: Debug:             EXPAND
%{%{control:PacketFence-Request-Time}:-0}
(727) Mon Oct 26 15:54:22 2020: Debug:                --> 0
(727) Mon Oct 26 15:54:22 2020: Debug:             if
("%{%{control:PacketFence-Request-Time}:-0}" != 0)  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:           } # policy request-timing
= noop
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: EXPAND type.reject.query
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject:    --> type.reject.query
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: Using query template
'query'
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: EXPAND %{User-Name}
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject:    --> coyo
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: SQL-User-Name set to
'coyo'
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: EXPAND INSERT INTO
radius_audit_log               ( mac, ip, computer_name, user_name,
       stripped_user_name,  realm, event_type,                switch_id,
switch_mac, switch_ip_address,                radius_source_ip_address,
called_station_id, calling_station_id,                nas_port_type, ssid,
nas_port_id,                ifindex, nas_port, connection_type,
   nas_ip_address, nas_identifier, auth_status,                reason,
auth_type, eap_type,                role, node_status, profile,
   source, auto_reg, is_phone,                pf_domain, uuid,
radius_request,                radius_reply, request_time, tenant_id,
radius_ip)              VALUES               (
'%{request:Calling-Station-Id}', '%{request:Framed-IP-Address}',
'%{%{control:PacketFence-Computer-Name}:-N/A}', '%{request:User-Name}',
           '%{request:Stripped-User-Name}', '%{request:Realm}',
'Radius-Access-Request',
 '%{%{control:PacketFence-Switch-Id}:-N/A}',
'%{%{control:PacketFence-Switch-Mac}:-N/A}',
'%{%{control:PacketFence-Switch-Ip-Address}:-N/A}',
 '%{Packet-Src-IP-Address}', '%{request:Called-Station-Id}',
'%{request:Calling-Station-Id}',                '%{request:NAS-Port-Type}',
'%{request:Called-Station-SSID}', '%{request:NAS-Port-Id}',
 '%{%{control:PacketFence-IfIndex}:-N/A}', '%{request:NAS-Port}',
'%{%{control:PacketFence-Connection-Type}:-N/A}',
 '%{request:NAS-IP-Address}', '%{request:NAS-Identifier}',  'Reject',
          '%{request:Module-Failure-Message}', '%{control:Auth-Type}',
'%{request:EAP-Type}',
 '%{%{control:PacketFence-Role}:-N/A}',
'%{%{control:PacketFence-Status}:-N/A}',
'%{%{control:PacketFence-Profile}:-N/A}',
 '%{%{control:PacketFence-Source}:-N/A}',
'%{%{control:PacketFence-AutoReg}:-0}',
'%{%{control:PacketFence-IsPhone}:-0}',
 '%{request:PacketFence-Domain}', '',
'%{pairs:&request:[*]}','%{pairs:&reply:[*]}',
'%{%{control:PacketFence-Request-Time}:-N/A}',
'%{control:PacketFence-Tenant-Id}', '%{request:PacketFence-Radius-Ip}')
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject:    --> INSERT INTO
radius_audit_log               ( mac, ip, computer_name, user_name,
       stripped_user_name,  realm, event_type,                switch_id,
switch_mac, switch_ip_address,                radius_source_ip_address,
called_station_id, calling_station_id,                nas_port_type, ssid,
nas_port_id,                ifindex, nas_port, connection_type,
   nas_ip_address, nas_identifier, auth_status,                reason,
auth_type, eap_type,                role, node_status, profile,
   source, auto_reg, is_phone,                pf_domain, uuid,
radius_request,                radius_reply, request_time, tenant_id,
radius_ip)              VALUES               ( 'X.X.X.X', '', 'N/A',
'coyo',                'coyo', 'null', 'Radius-Access-Request',
   'N/A', 'N/A', 'N/A',                'X.X.X.X', 'X.X.X.X', 'X.X.X.X',
           'Virtual', '', '',                'N/A', '39', 'N/A',
     'X.X.X.X', 'MK-IBERA2',  'Reject',                 'mschap: Program
returned code (1) and output =27Reading winbind reply failed=21
(0xc0000001)=27', 'MS-CHAP', '',                'N/A', 'N/A', 'N/A',
         'N/A', '0', '0',                '', '', 'NAS-Port-Type =3D
Virtual, Acct-Session-Id =3D =2281d00cdf=22, PacketFence-Radius-Ip =3D
=22X.X.X.X=22, Service-Type =3D Framed-User, Called-Station-Id =3D
=22X.X.X.X=22, Realm =3D =22null=22, NAS-IP-Address =3D X.X.X.X,
PacketFence-NTLMv2-Only =3D =22=22, Calling-Station-Id =3D =22X.X.X.X=22,
PacketFence-KeyBalanced =3D =22865fdf018805bc0bc5fbb22eaa6b0a60=22,
FreeRADIUS-Client-IP-Address =3D X.X.X.X, MS-CHAP-Challenge =3D
0xebf6d832753d4fdf8383548a74da2637, Framed-Protocol =3D PPP, User-Name =3D
=22coyo=22, NAS-Identifier =3D =22MK-IBERA2=22, Event-Timestamp =3D =22Oct
26 2020 15:54:22 -03=22, MS-CHAP2-Response =3D
0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5,
NAS-Port =3D 39, Stripped-User-Name =3D =22coyo=22, Module-Failure-Message
=3D =22mschap: Program returned code (1) and output =27Reading winbind
reply failed=21 (0xc0000001)=27=22, Module-Failure-Message =3D =22mschap:
Reading winbind reply failed=21 (0xc0000001)=22, User-Password =3D
=22=2A=2A=2A=2A=2A=2A=22, SQL-User-Name =3D =22coyo=22','MS-CHAP-Error =3D
=22=5C001E=3D691 R=3D0 C=3Dc86ce57de86611d248ddad2f2eb690ab V=3D3
M=3DAuthentication failed=22', '0', '1', 'X.X.X.X')
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: Executing query: INSERT
INTO radius_audit_log               ( mac, ip, computer_name, user_name,
             stripped_user_name,  realm, event_type,
 switch_id, switch_mac, switch_ip_address,
 radius_source_ip_address, called_station_id, calling_station_id,
     nas_port_type, ssid, nas_port_id,                ifindex, nas_port,
connection_type,                nas_ip_address, nas_identifier,
auth_status,                reason, auth_type, eap_type,
 role, node_status, profile,                source, auto_reg, is_phone,
           pf_domain, uuid, radius_request,                radius_reply,
request_time, tenant_id, radius_ip)              VALUES               (
'X.X.X.X', '', 'N/A', 'coyo',                'coyo', 'null',
'Radius-Access-Request',                'N/A', 'N/A', 'N/A',
 'X.X.X.X', 'X.X.X.X', 'X.X.X.X',                'Virtual', '', '',
       'N/A', '39', 'N/A',                'X.X.X.X', 'MK-IBERA2',
 'Reject',                 'mschap: Program returned code (1) and output
=27Reading winbind reply failed=21 (0xc0000001)=27', 'MS-CHAP', '',
       'N/A', 'N/A', 'N/A',                'N/A', '0', '0',
 '', '', 'NAS-Port-Type =3D Virtual, Acct-Session-Id =3D =2281d00cdf=22,
PacketFence-Radius-Ip =3D =22X.X.X.X=22, Service-Type =3D Framed-User,
Called-Station-Id =3D =22X.X.X.X=22, Realm =3D =22null=22, NAS-IP-Address
=3D X.X.X.X, PacketFence-NTLMv2-Only =3D =22=22, Calling-Station-Id =3D
=22X.X.X.X=22, PacketFence-KeyBalanced =3D
=22865fdf018805bc0bc5fbb22eaa6b0a60=22, FreeRADIUS-Client-IP-Address =3D
X.X.X.X, MS-CHAP-Challenge =3D 0xebf6d832753d4fdf8383548a74da2637,
Framed-Protocol =3D PPP, User-Name =3D =22coyo=22, NAS-Identifier =3D
=22MK-IBERA2=22, Event-Timestamp =3D =22Oct 26 2020 15:54:22 -03=22,
MS-CHAP2-Response =3D
0x0100abb873a94cda9a306246c4fef05e7a900000000000000000b44e09097c106ee6479636c7545e3fdd9b27a86cdbfa77a5,
NAS-Port =3D 39, Stripped-User-Name =3D =22coyo=22, Module-Failure-Message
=3D =22mschap: Program returned code (1) and output =27Reading winbind
reply failed=21 (0xc0000001)=27=22, Module-Failure-Message =3D =22mschap:
Reading winbind reply failed=21 (0xc0000001)=22, User-Password =3D
=22=2A=2A=2A=2A=2A=2A=22, SQL-User-Name =3D =22coyo=22','MS-CHAP-Error =3D
=22=5C001E=3D691 R=3D0 C=3Dc86ce57de86611d248ddad2f2eb690ab V=3D3
M=3DAuthentication failed=22', '0', '1', 'X.X.X.X')
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: SQL query returned:
success
(727) Mon Oct 26 15:54:22 2020: Debug: sql_reject: 1 record(s) updated
(727) Mon Oct 26 15:54:22 2020: Debug:           [sql_reject] = ok
(727) Mon Oct 26 15:54:22 2020: Debug:         } # else = ok
(727) Mon Oct 26 15:54:22 2020: Debug:       } # policy
packetfence-audit-log-reject = ok
(727) Mon Oct 26 15:54:22 2020: Debug:     } # if (! EAP-Type || (EAP-Type
!= TTLS  && EAP-Type != PEAP) )  = ok
(727) Mon Oct 26 15:54:22 2020: Debug:     if
("%{%{control:PacketFence-Proxied-From}:-False}" == "True") {
(727) Mon Oct 26 15:54:22 2020: Debug:     EXPAND
%{%{control:PacketFence-Proxied-From}:-False}
(727) Mon Oct 26 15:54:22 2020: Debug:        --> False
(727) Mon Oct 26 15:54:22 2020: Debug:     if
("%{%{control:PacketFence-Proxied-From}:-False}" == "True")  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.access_reject: EXPAND
%{User-Name}
(727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.access_reject:    -->
coyo
(727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.access_reject: Matched
entry DEFAULT at line 11
(727) Mon Oct 26 15:54:22 2020: Debug:     [attr_filter.access_reject] =
updated
(727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.packetfence_post_auth:
EXPAND %{User-Name}
(727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.packetfence_post_auth:
 --> coyo
(727) Mon Oct 26 15:54:22 2020: Debug: attr_filter.packetfence_post_auth:
Matched entry DEFAULT at line 10
(727) Mon Oct 26 15:54:22 2020: Debug:
[attr_filter.packetfence_post_auth] = updated
(727) Mon Oct 26 15:54:22 2020: Debug:     [eap] = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     policy
remove_reply_message_if_eap {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (&reply:EAP-Message &&
&reply:Reply-Message) {
(727) Mon Oct 26 15:54:22 2020: Debug:       if (&reply:EAP-Message &&
&reply:Reply-Message)  -> FALSE
(727) Mon Oct 26 15:54:22 2020: Debug:       else {
(727) Mon Oct 26 15:54:22 2020: Debug:         [noop] = noop
(727) Mon Oct 26 15:54:22 2020: Debug:       } # else = noop
(727) Mon Oct 26 15:54:22 2020: Debug:     } # policy
remove_reply_message_if_eap = noop
(727) Mon Oct 26 15:54:22 2020: Debug: linelog: EXPAND
messages.%{%{reply:Packet-Type}:-default}
(727) Mon Oct 26 15:54:22 2020: Debug: linelog:    -->
messages.Access-Reject
(727) Mon Oct 26 15:54:22 2020: Debug: linelog: EXPAND
[mac:%{Calling-Station-Id}] Rejected user: %{User-Name}
(727) Mon Oct 26 15:54:22 2020: Debug: linelog:    --> [mac:X.X.X.X]
Rejected user: coyo
(727) Mon Oct 26 15:54:22 2020: Debug:     [linelog] = ok
(727) Mon Oct 26 15:54:22 2020: Debug:   } # Post-Auth-Type REJECT = updated
(727) Mon Oct 26 15:54:22 2020: Debug: Delaying response for 1.000000
seconds
(727) Mon Oct 26 15:54:23 2020: Debug: (727) Discarding duplicate request
from client X.X.X.X/32 port 55645 - ID: 132 due to delayed response
(727) Mon Oct 26 15:54:23 2020: Debug: Sending delayed response
(727) Mon Oct 26 15:54:23 2020: Debug: Sent Access-Reject Id 132 from
X.X.X.X:1812 to X.X.X.X:55645 length 101
(727) Mon Oct 26 15:54:23 2020: Debug:   MS-CHAP-Error = "\001E=691 R=0
C=c86ce57de86611d248ddad2f2eb690ab V=3 M=Authentication failed"
(727) Mon Oct 26 15:54:27 2020: Debug: Cleaning up request packet ID 132
with timestamp +10785
(728) Mon Oct 26 15:54:30 2020: Debug: Received Status-Server Id 199 from
127.0.0.1:50706 to 127.0.0.1:18121 length 50
(728) Mon Oct 26 15:54:30 2020: Debug:   Message-Authenticator =
0x746e4169562dc5520ee77b953ef0ac7b
(728) Mon Oct 26 15:54:30 2020: Debug:   FreeRADIUS-Statistics-Type = 15
(728) Mon Oct 26 15:54:30 2020: Debug: # Executing group from file
/usr/local/pf/raddb/sites-enabled/status
(728) Mon Oct 26 15:54:30 2020: Debug:   Autz-Type Status-Server {
(728) Mon Oct 26 15:54:30 2020: Debug:     [ok] = ok
(728) Mon Oct 26 15:54:30 2020: Debug:   } # Autz-Type Status-Server = ok

El lun., 26 oct. 2020 a las 12:39, Fabrice Durand via PacketFence-users (<
packetfence-users@lists.sourceforge.net>) escribió:

> Hello Enrique,
>
> can you provide the raddebug output ?
>
> raddebug -f /usr/local/pf/var/run/radiusd.sock -t 3000
>
>
> Regards
>
> Fabrice
>
>
> Le 20-10-26 à 09 h 42, Enrique Gross via PacketFence-users a écrit :
> > Hi Packetfence Users,
> >
> > Hope you are doing fine
> >
> > I am struggling to authenticate PPP users via MSCHAP with local PF
> > authentication, my switch is a Mikrotik device, I am forwarding
> > authentication via Radius to packetfence server.
> >
> > I am getting error
> >
> > (144) Login incorrect (mschap: Program returned code (1) and output
> > 'Reading winbind reply failed!
> >
> > When I disable MSCHAP/CHAP as an authentication method and use PAP my
> > users can authenticate fine.
> >
> > I have uncomment /usr/local/pf/conf/radiusd/packetfence-tunnel and
> > Take care of the "Database passwords hashing method"
> >
> > I will really appreciate any help
> >
> > Thanks, Enrique
> >
> > --
> >
> >
> > _______________________________________________
> > PacketFence-users mailing list
> > PacketFence-users@lists.sourceforge.net
> > https://lists.sourceforge.net/lists/listinfo/packetfence-users
>
> --
> Fabrice Durand
> fdur...@inverse.ca ::  +1.514.447.4918 (x135) ::  www.inverse.ca
> Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence (
> http://packetfence.org)
>
>
>
> _______________________________________________
> PacketFence-users mailing list
> PacketFence-users@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/packetfence-users
>


-- 

[image: Imágenes integradas 1]
_______________________________________________
PacketFence-users mailing list
PacketFence-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/packetfence-users

Reply via email to