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
