Thanks Fabrice I probably messed up something, and should start over with my testing setup, this isjournalctl when starting radiusd, i have been checking config files regarding sql modules, but with not luck.
Thanks, and good weekend Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql_mysql: Starting connect to MySQL server Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (sql): Reserved connection (0) Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (sql): Released connection (0) Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (pfguest): Attempting to connect to database "pf" Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (pfsponsor): Attempting to connect to database "pf" Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (pfsms): Attempting to connect to database "pf" Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (pflocal): Attempting to connect to database "pf" Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (sql_reject): groupmemb_query is empty. Please delete it from the configuration Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (sql_reject): authorize_check_query is empty. Please delete it from the configuration Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (sql_reject): Attempting to connect to database "pf" Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (sql_degraded): groupmemb_query is empty. Please delete it from the configuration Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (sql_degraded): Ignoring read_groups as group_membership_query is not configured Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_sql (sql_degraded): Attempting to connect to database "pf" Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_mschap (mschap): authenticating by calling 'ntlm_auth' Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_mschap (chrooted_mschap): authenticating by calling 'ntlm_auth' Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_mschap (chrooted_mschap_machine): authenticating by calling 'ntlm_auth' Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_mschap (mschap_machine): authenticating by calling 'ntlm_auth' Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: rlm_mschap (mschap_local): using internal authentication Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: /usr/local/pf/raddb/policy.d/packetfence[15]: "sql" modules aren't allowed in 'authenticate' sections -- they have no such method. Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: /usr/local/pf/raddb/policy.d/packetfence[15]: Failed to parse "pflocal" entry. Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: /usr/local/pf/raddb/policy.d/packetfence[145]: Failed to parse "packetfence-local-auth" entry. Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: /usr/local/pf/raddb/policy.d/packetfence[144]: Failed to parse "else" subsection. Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: /usr/local/pf/raddb/policy.d/packetfence[140]: Failed to parse "else" subsection. Oct 31 00:53:38 pf.jcc.com.ar radiusd[17061]: /usr/local/pf/raddb/sites-enabled/packetfence[190]: Failed to parse "packetfence-mschap-authenticate" entry. Oct 31 00:53:38 pf.jcc.com.ar systemd[1]: packetfence-radiusd-auth.service: control process exited, code=exited status=1 El vie., 30 oct. 2020 a las 19:59, Durand fabrice (<fdur...@inverse.ca>) escribió: > 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 > >> > >> > >> -- > >> > >> > > > > -- > > -- [image: Imágenes integradas 1]
_______________________________________________ PacketFence-users mailing list PacketFence-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/packetfence-users