Re: [PacketFence-users] MSCHAP and Local Auth

[Durand fabrice via PacketFence-users]

Hello Enrique,

i did the same on my side and i am able to restart radiusd.

Take a look at journalctl to see why it fail to start.

Regards

Fabrice


Le 20-10-30 à 14 h 44, Enrique Gross a écrit :

Hi all!

Thanks for your help Fabrice

When changing function to packetfence-local-auth, radius-auth fails to
start, i am not getting so much info of radius.log

Oct 30 18:39:09 pf auth[7031]: Signalled to terminate
Oct 30 18:39:09 pf auth[7031]: Exiting normally
Oct 30 18:39:09 pf auth[7031]: rlm_perl: rlm_perl::Detaching. Reloading. Done.
Oct 30 18:39:09 pf auth[7031]: rlm_perl: rlm_perl::Detaching. Reloading. Done.

And packetfence.log

Oct 30 18:39:09 pf packetfence: pfperl-api(2390) INFO: Stopping
radiusd-auth with pid 7031 (pf::services::manager::stopService)
Oct 30 18:39:09 pf packetfence: pfperl-api(2390) INFO: child exited with value 0
  (pf::services::manager::stopService)
Oct 30 18:39:14 pf packetfence: pfperl-api(2394) INFO: Daemon
radiusd-auth took 2.123 seconds to start.
(pf::services::manager::launchService)

Thanks!


El jue., 29 oct. 2020 a las 21:57, Durand fabrice
(<fdur...@inverse.ca>) escribió:

Hello Enrique,

sorry for the late reply.

So ppp mschap with local pf account is not really implemented.

What you can try is to edit /usr/local/pf/raddb/policy.d/packetfence and find 
the following function:

packetfence-mschap-authenticate {
     if(PacketFence-Domain) {
       if ( "%{User-Name}" =~ /^host\/.*/) {
         chrooted_mschap_machine
       }
       else {
         chrooted_mschap
       }
     }
     else {
       if ( "%{User-Name}" =~ /^host\/.*/) {
         mschap_machine
       }
       else {
         mschap
       }
     }
}


and replace it with:

packetfence-mschap-authenticate {
     if(PacketFence-Domain) {
       if ( "%{User-Name}" =~ /^host\/.*/) {
         chrooted_mschap_machine
       }
       else {
         chrooted_mschap
       }
     }
     else {
       if ( "%{User-Name}" =~ /^host\/.*/) {
         mschap_machine
       }
       else {
         packetfence-local-auth
       }
     }
}

Then restart radius and retry.

Let me know if it works.

Regards

Fabrice


Le 20-10-26 à 12 h 15, Enrique Gross a écrit :

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

--

--

_______________________________________________
PacketFence-users mailing list
PacketFence-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/packetfence-users