Hello, perhaps in the portal, you don't have check the autoregister box

Le jeudi 13 février 2020, Jeff Linden via PacketFence-users <
[email protected]> a écrit :

> Hello all,
>
>
>
> Before the end of the year, I had PacketFence version 8.<something> up and
> running in my lab with 802.1x authenticating successfully for multiple
> domains and auto-registering devices.  Captive portal was functioning, but
> very slowly.  It seemed none of the timing options in the Advanced Access
> Configuration->Captive Portal section were having any effect.
>
>
>
> At this point, I decided to upgrade to version 9.2.0.  It was my first
> upgrade of PacketFence.  Maybe not the smoothest execution of an upgrade
> that was ever performed, but I did find the documentation about the extra
> perl scripts to run and the database schema updates, etc.
>
>
>
> Once I completed the upgrade, I found the Captive Portal timing options
> appeared to work as expected.  However, 802.1x suffered a setback.  Users
> could authenticate successfully, but the nodes were not being automatically
> registered.  In fact, they didn’t show up in the Nodes pane at all.
>
>
>
> After some fruitless investigation, I decided to wipe out the PacketFence
> configuration (including FreeRadius and MariaDB.)  Completely removed all
> the relevant software with the apt-get tool.  Then, I re-installed.  It
> didn’t go smoothly and I did it more than once, but the software is all
> back up and running.
>
>
>
> I had saved some of my original configuration files and, along the way,
> tried to use some of them with mixed results.
>
>
>
> In this final iteration, the only configuration file I restored from my
> original install is switches.conf.  And, I’m having no perceived difficulty
> with communication between the switches and PacketFence.
>
>
>
> My current difficulty is that 802.1x authentication is failing and I
> cannot understand why.  Here are some configuration details:
>
>
>
>    - Three Active Directory domains are configured with successful Joins.
>    - Matching Realms exist, one for each of the three domains
>    - For each domain, a matching Authentication Source exists with a
>    CatchAll rule setting the Role as default and Access duration as 5 days
>    - There is one Connection Profile with all three Authentication
>    Sources defined and the switch activated to Automatically Register Devices
>    - Two switches, the same as in the original configuration.
>    - Supplicant is Windows 10 (multiple clients producing the same result)
>
>
>
>
>
> Below is some log data.  The most significant things I can find are as
> follows:
>
>
>
>    - radius.log reports “Invalid user”.  I’ve sanitized the log data, but
>    the domain, username and password are valid in the domain.  Windows is just
>    passing on my user credentials I use every day.
>    - raddb reports [packetfence-multi-domain] = fail.  I’ve not found any
>    other clues in the log data to indicate why it is failing.  My hope was the
>    Invalid User message would be more verbose here, but it’s not represented
>    in the raddb data at all.
>
>
>
> I will appreciate any assistance getting me pointed in the right direction.
>
>
>
> Thank you,
>
>
>
> Jeff
>
>
>
> --------------------------
>
>
>
>
>
> /usr/local/pf/logs/radius.log
>
>
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: (49309)   Invalid user:
> [MYDOMAIN\myuser] (from client 1.1.1.1/32 port 564 cli f0:1f:af:23:73:6d
> via TLS tunnel)
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: (49309)   Login incorrect
> (Failed retrieving values required to evaluate condition):
> [MYDOMAIN\myuser] (from client 1.1.1.1/32 port 564 cli f0:1f:af:23:73:6d
> via TLS tunnel)
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: [mac:f0:1f:af:23:73:6d]
> Rejected user: MYDOMAIN\myuser
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: (49310) Login incorrect
> (eap_peap: The users session was previously rejected: returning reject
> (again.)): [MYDOMAIN\myuser] (from client 1.1.1.1/32 port 564 cli
> f0:1f:af:23:73:6d)
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: Need 2 more connections to
> reach 10 spares
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: rlm_sql (sql): Opening
> additional connection (255), 1 of 56 pending slots used
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: (49309)   Invalid user:
> [MYDOMAIN\myuser] (from client 1.1.1.1/32 port 564 cli f0:1f:af:23:73:6d
> via TLS tunnel)
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: (49309)   Login incorrect
> (Failed retrieving values required to evaluate condition):
> [MYDOMAIN\myuser] (from client 1.1.1.1/32 port 564 cli f0:1f:af:23:73:6d
> via TLS tunnel)
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: [mac:f0:1f:af:23:73:6d]
> Rejected user: MYDOMAIN\myuser
>
> Feb 13 16:46:55 nadc1-pfence-01 auth[7557]: (49310) Login incorrect
> (eap_peap: The users session was previously rejected: returning reject
> (again.)): [MYDOMAIN\myuser] (from client 1.1.1.1/32 port 564 cli
> f0:1f:af:23:73:6d)
>
>
>
>
>
>
>
>
>
>
>
> Log data collected with raddb tool
>
>
>
>
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: Received Access-Request Id 50
> from 1.1.1.1:62346 to 2.2.2.2:1812 length 231
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   User-Name = "MYDOMAIN\\myuser"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   NAS-Port = 564
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   State =
> 0xa7aca802a1abb1731d68285805a095a1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   EAP-Message =
> 0x020700361900170303002b0000000000000001c5b68a46bf78d5edf7fc
> 184f64dba1119a9284ca3ae053917e4c0b39e51fcc61d031ae
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Message-Authenticator =
> 0x16e19f834e7374ca1f5ae680d48502d7
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Acct-Session-Id =
> "8O2.1x810203cc00016034"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   NAS-Port-Id = "ge-0/0/8.0"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Calling-Station-Id =
> "f0-1f-af-23-73-6d"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Called-Station-Id =
> "58-00-bb-37-ad-40"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   NAS-Identifier = "LAB-4300-VC"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   NAS-Port-Type = Ethernet
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: Restoring &session-state
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   
> &session-state:TLS-Session-Cipher-Suite
> = "ECDHE-RSA-AES256-GCM-SHA384"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   &session-state:TLS-Session-Version
> = "TLS 1.2"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: # Executing section authorize
> from file /usr/local/pf/raddb/sites-enabled/packetfence
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   authorize {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     update {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       EXPAND
> %{Packet-Src-IP-Address}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:          --> 1.1.1.1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       EXPAND
> %{Packet-Dst-IP-Address}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:          --> 2.2.2.2
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       EXPAND %l
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:          --> 1581619615
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # update = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     policy
> packetfence-set-realm-if-machine {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (User-Name =~
> /host\/([a-z0-9_-]*)[\.](.*)/i) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (User-Name =~
> /host\/([a-z0-9_-]*)[\.](.*)/i)  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # policy
> packetfence-set-realm-if-machine = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     policy
> packetfence-balanced-key-policy {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if
> (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i)) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if
> (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.*)(.)$/i))
> -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       else {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         update {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           EXPAND
> %{md5:%{Calling-Station-Id}%{User-Name}}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:              -->
> eb1f6320f59f6feba568d08011260431
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           EXPAND
> %{md5:%{Calling-Station-Id}%{User-Name}}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:              -->
> eb1f6320f59f6feba568d08011260431
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         } # update = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # else = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # policy
> packetfence-balanced-key-policy = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     policy
> packetfence-set-tenant-id {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (!NAS-IP-Address ||
> NAS-IP-Address == "0.0.0.0"){
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (!NAS-IP-Address ||
> NAS-IP-Address == "0.0.0.0") -> TRUE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (!NAS-IP-Address ||
> NAS-IP-Address == "0.0.0.0") {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         update request {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           EXPAND
> %{Packet-Src-IP-Address}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:              --> 1.1.1.1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         } # update request = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # if (!NAS-IP-Address ||
> NAS-IP-Address == "0.0.0.0") = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       EXPAND
> %{%{control:PacketFence-Tenant-Id}:-0}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:          --> 0
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  -> TRUE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         update control {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           EXPAND %{User-Name}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:              --> MYDOMAIN\\myuser
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           SQL-User-Name set to
> 'MYDOMAIN\\myuser'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           Executing select
> query:  SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
> '1.1.1.1'), 0)
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           EXPAND %{sql: SELECT
> IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
> '%{NAS-IP-Address}'), 0)}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:              --> 1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         } # update control = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (
> &control:PacketFence-Tenant-Id == 0 ) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (
> &control:PacketFence-Tenant-Id == 0 )  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # policy
> packetfence-set-tenant-id = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     policy
> rewrite_calling_station_id {
>
> (47157) Thu Feb 13 13:46:55 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)) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (&Calling-Station-Id &&
> (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-
> 9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-
> 9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
>
> (47157) Thu Feb 13 13:46:55 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))  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         update request {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           EXPAND
> %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:              --> f0:1f:af:23:73:6d
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         } # update request = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         [updated] = updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # if (&Calling-Station-Id
> && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-
> 9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-
> 9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       ... skipping else:
> Preceding "if" was taken
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # policy
> rewrite_calling_station_id = updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     policy
> rewrite_called_station_id {
>
> (47157) Thu Feb 13 13:46:55 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)) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if ((&Called-Station-Id) &&
> (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-
> 9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-
> 9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))  -> TRUE
>
> (47157) Thu Feb 13 13:46:55 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))  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         update request {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           EXPAND
> %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:              --> 58:00:bb:37:ad:40
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         } # update request = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if ("%{8}") {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         EXPAND %{8}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:            -->
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if ("%{8}")  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         elsif ( (Colubris-AVPair)
> && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         elsif ( (Colubris-AVPair)
> && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i)  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         elsif (Aruba-Essid-Name) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         elsif (Aruba-Essid-Name)
> -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         elsif ( (Cisco-AVPair)
> && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         elsif ( (Cisco-AVPair)
> && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i)  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         [updated] = updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # if
> ((&Called-Station-Id) && (&Called-Station-Id =~
> /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{
> 2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i))
> = updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       ... skipping else:
> Preceding "if" was taken
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # policy
> rewrite_called_station_id = updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     policy filter_username {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (&User-Name) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (&User-Name)  -> TRUE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (&User-Name)  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~ / /) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~ / /)
> -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~
> /@[^@]*@/ ) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~
> /@[^@]*@/ )  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~ /\.\./
> ) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~ /\.\./
> )  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if ((&User-Name =~ /@/)
> && (&User-Name !~ /@(.+)\.(.+)$/))  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if ((&User-Name =~ /@/)
> && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~ /\.$/)
> {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~
> /\.$/)   -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~ /@\./)
> {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name =~
> /@\./)   -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # if (&User-Name)  =
> updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # policy filter_username =
> updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     policy filter_password {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (&User-Password &&
> (&User-Password != "%{string:User-Password}")) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if (&User-Password &&
> (&User-Password != "%{string:User-Password}"))  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # policy filter_password =
> updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     [preprocess] = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: suffix: Checking for suffix after
> "@"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: suffix: No '@' in User-Name =
> "MYDOMAIN\myuser", skipping NULL due to config.
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     [suffix] = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Checking for prefix
> before "\"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Looking up realm
> "MYDOMAIN" for User-Name = "MYDOMAIN\myuser"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Found realm "MYDOMAIN"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Adding
> Stripped-User-Name = "myuser"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Adding Realm =
> "MYDOMAIN"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Authentication realm is
> LOCAL
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     [ntdomain] = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap: Peer sent EAP Response (code
> 2) ID 7 length 54
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap: Continuing tunnel setup
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     [eap] = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   } # authorize = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: Found Auth-Type = eap
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: # Executing group from file
> /usr/local/pf/raddb/sites-enabled/packetfence
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   authenticate {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap: Expiring EAP session with
> state 0xa7aca802a1abb173
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap: Finished EAP session with
> state 0xa7aca802a1abb173
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap: Previous EAP request found
> for state 0xa7aca802a1abb173, released from the list
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap: Peer sent packet with method
> EAP PEAP (25)
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap: Calling submodule eap_peap
> to process data
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Continuing EAP-TLS
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: [eaptls verify] = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Done initial handshake
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: [eaptls process] = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Session established.
> Decoding tunneled attributes
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: PEAP state WAITING FOR
> INNER IDENTITY
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Identity -
> MYDOMAIN\myuser
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Got inner identity
> 'MYDOMAIN\myuser'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Setting default EAP
> type for tunneled EAP session
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Got tunneled request
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   EAP-Message =
> 0x020700170144414946554b554e415c316a6c696e64656e
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Setting User-Name to
> MYDOMAIN\myuser
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Sending tunneled
> request to packetfence-tunnel
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   EAP-Message =
> 0x020700170144414946554b554e415c316a6c696e64656e
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   FreeRADIUS-Proxied-To
> = 127.0.0.1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   User-Name =
> "MYDOMAIN\\myuser"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   NAS-Port = 564
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   Acct-Session-Id =
> "8O2.1x810203cc00016034"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   NAS-Port-Id =
> "ge-0/0/8.0"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   Calling-Station-Id :=
> "f0:1f:af:23:73:6d"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   NAS-Identifier =
> "LAB-4300-VC"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   NAS-Port-Type =
> Ethernet
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   PacketFence-Radius-Ip
> := "2.2.2.2"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:
> PacketFence-KeyBalanced := "eb1f6320f59f6feba568d08011260431"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   NAS-IP-Address :=
> 1.1.1.1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   Called-Station-Id :=
> "58:00:bb:37:ad:40"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap:   Event-Timestamp =
> "Feb 13 2020 13:46:55 EST"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: Virtual server packetfence-tunnel
> received request
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   EAP-Message =
> 0x020700170144414946554b554e415c316a6c696e64656e
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   FreeRADIUS-Proxied-To =
> 127.0.0.1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   User-Name = "MYDOMAIN\\myuser"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   NAS-Port = 564
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Acct-Session-Id =
> "8O2.1x810203cc00016034"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   NAS-Port-Id = "ge-0/0/8.0"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Calling-Station-Id :=
> "f0:1f:af:23:73:6d"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   NAS-Identifier = "LAB-4300-VC"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   NAS-Port-Type = Ethernet
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   PacketFence-Radius-Ip :=
> "2.2.2.2"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   PacketFence-KeyBalanced := "
> eb1f6320f59f6feba568d08011260431"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   NAS-IP-Address := 1.1.1.1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Called-Station-Id :=
> "58:00:bb:37:ad:40"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Event-Timestamp = "Feb 13 2020
> 13:46:55 EST"
>
> (47157) Thu Feb 13 13:46:55 2020: WARNING: Outer and inner identities are
> the same.  User privacy is compromised.
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: server packetfence-tunnel {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   # Executing section authorize
> from file /usr/local/pf/raddb/sites-enabled/packetfence-tunnel
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     authorize {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if ( outer.EAP-Type ==
> TTLS) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       if ( outer.EAP-Type ==
> TTLS)  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       policy
> packetfence-set-realm-if-machine {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (User-Name =~
> /host\/([a-z0-9_-]*)[\.](.*)/i) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (User-Name =~
> /host\/([a-z0-9_-]*)[\.](.*)/i)  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # policy
> packetfence-set-realm-if-machine = notfound
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       policy
> packetfence-set-tenant-id {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (!NAS-IP-Address ||
> NAS-IP-Address == "0.0.0.0"){
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (!NAS-IP-Address ||
> NAS-IP-Address == "0.0.0.0") -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         EXPAND
> %{%{control:PacketFence-Tenant-Id}:-0}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:            --> 0
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  -> TRUE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           update control {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:             EXPAND %{User-Name}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:                -->
> MYDOMAIN\\myuser
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:             SQL-User-Name set to
> 'MYDOMAIN\\myuser'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:             Executing select
> query:  SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
> '1.1.1.1'), 0)
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:             EXPAND %{sql: SELECT
> IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname =
> '%{NAS-IP-Address}'), 0)}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:                --> 1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           } # update control =
> noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         } # if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (
> &control:PacketFence-Tenant-Id == 0 ) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (
> &control:PacketFence-Tenant-Id == 0 )  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # policy
> packetfence-set-tenant-id = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       policy filter_username {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name)  -> TRUE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name)  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~ / /) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~ / /)
> -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~
> /@[^@]*@/ ) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~
> /@[^@]*@/ )  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~
> /\.\./ ) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~
> /\.\./ )  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if ((&User-Name =~ /@/)
> && (&User-Name !~ /@(.+)\.(.+)$/))  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if ((&User-Name =~ /@/)
> && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~
> /\.$/)  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~
> /\.$/)   -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~
> /@\./)  {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           if (&User-Name =~
> /@\./)   -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         } # if (&User-Name)  =
> noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # policy filter_username
> = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       [mschap] = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: suffix: Checking for suffix after
> "@"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: suffix: No '@' in User-Name =
> "MYDOMAIN\myuser", skipping NULL due to config.
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       [suffix] = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Looking up realm
> "MYDOMAIN" for User-Name = "MYDOMAIN\myuser"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Found realm "MYDOMAIN"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Adding
> Stripped-User-Name = "myuser"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Adding Realm =
> "MYDOMAIN"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: ntdomain: Authentication realm is
> LOCAL
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       [ntdomain] = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'User-Name'} = &request:User-Name -> 'MYDOMAIN\myuser'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'NAS-IP-Address'} = &request:NAS-IP-Address -> '1.1.1.1'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'NAS-Port'} = &request:NAS-Port -> '564'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'Called-Station-Id'} = &request:Called-Station-Id ->
> '58:00:bb:37:ad:40'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'Calling-Station-Id'} = &request:Calling-Station-Id ->
> 'f0:1f:af:23:73:6d'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'NAS-Identifier'} = &request:NAS-Identifier -> 'LAB-4300-VC'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'NAS-Port-Type'} = &request:NAS-Port-Type -> 'Ethernet'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'Acct-Session-Id'} = &request:Acct-Session-Id ->
> '8O2.1x810203cc00016034'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'Event-Timestamp'} = &request:Event-Timestamp -> 'Feb 13
> 2020 13:46:55 EST'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'EAP-Message'} = &request:EAP-Message -> '
> 0x020700170144414946554b554e415c316a6c696e64656e'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'NAS-Port-Id'} = &request:NAS-Port-Id -> 'ge-0/0/8.0'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'FreeRADIUS-Proxied-To'} = &request:FreeRADIUS-Proxied-To ->
> '127.0.0.1'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'Stripped-User-Name'} = &request:Stripped-User-Name ->
> 'myuser'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'Realm'} = &request:Realm -> 'MYDOMAIN'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'SQL-User-Name'} = &request:SQL-User-Name -> 'MYDOMAIN\\myuser'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'PacketFence-KeyBalanced'} = &request:PacketFence-KeyBalanced
> -> 'eb1f6320f59f6feba568d08011260431'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_REQUEST{'PacketFence-Radius-Ip'} = &request:PacketFence-Radius-Ip ->
> '2.2.2.2'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_CHECK{'EAP-Type'} = &control:EAP-Type -> 'MSCHAPv2'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_CHECK{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id ->
> '1'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_CONFIG{'EAP-Type'} = &control:EAP-Type -> 'MSCHAPv2'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> $RAD_CONFIG{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id ->
> '1'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> perl_embed:: module = /usr/local/pf/raddb/mods-config/perl/
> packetfence-multi-domain.pm , func = authorize exit status= hash- or
> arrayref expected (not a simple scalar, use allow_nonref to allow this) at
> /usr/local/pf/lib/pfconfig/cached.pm line 182.
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:Realm = $RAD_REQUEST{'Realm'} -> 'MYDOMAIN'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:NAS-Port = $RAD_REQUEST{'NAS-Port'} -> '564'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:PacketFence-Radius-Ip = $RAD_REQUEST{'PacketFence-Radius-Ip'} ->
> '2.2.2.2'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:User-Name = $RAD_REQUEST{'User-Name'} -> 'MYDOMAIN\myuser'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:FreeRADIUS-Proxied-To = $RAD_REQUEST{'FreeRADIUS-Proxied-To'} ->
> '127.0.0.1'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:NAS-Port-Type = $RAD_REQUEST{'NAS-Port-Type'} -> 'Ethernet'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:Acct-Session-Id = $RAD_REQUEST{'Acct-Session-Id'} ->
> '8O2.1x810203cc00016034'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:Called-Station-Id = $RAD_REQUEST{'Called-Station-Id'} ->
> '58:00:bb:37:ad:40'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:Event-Timestamp = $RAD_REQUEST{'Event-Timestamp'} -> 'Feb 13
> 2020 13:46:55 EST'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:EAP-Message = $RAD_REQUEST{'EAP-Message'} -> '
> 0x020700170144414946554b554e415c316a6c696e64656e'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:PacketFence-KeyBalanced = $RAD_REQUEST{'PacketFence-KeyBalanced'}
> -> 'eb1f6320f59f6feba568d08011260431'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:NAS-IP-Address = $RAD_REQUEST{'NAS-IP-Address'} -> '1.1.1.1'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:Stripped-User-Name = $RAD_REQUEST{'Stripped-User-Name'} ->
> 'myuser'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:SQL-User-Name = $RAD_REQUEST{'SQL-User-Name'} -> 'MYDOMAIN\\myuser'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:NAS-Port-Id = $RAD_REQUEST{'NAS-Port-Id'} -> 'ge-0/0/8.0'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:NAS-Identifier = $RAD_REQUEST{'NAS-Identifier'} -> 'LAB-4300-VC'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &request:Calling-Station-Id = $RAD_REQUEST{'Calling-Station-Id'} ->
> 'f0:1f:af:23:73:6d'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &control:PacketFence-Tenant-Id = $RAD_CHECK{'PacketFence-Tenant-Id'} ->
> '1'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: packetfence-multi-domain:
> &control:EAP-Type = $RAD_CHECK{'EAP-Type'} -> 'MSCHAPv2'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       [packetfence-multi-domain]
> = fail
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # authorize = fail
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Using Post-Auth-Type Reject
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   # Executing group from file
> /usr/local/pf/raddb/sites-enabled/packetfence-tunnel
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     Post-Auth-Type REJECT {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       policy
> packetfence-set-tenant-id {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (!NAS-IP-Address ||
> NAS-IP-Address == "0.0.0.0"){
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (!NAS-IP-Address ||
> NAS-IP-Address == "0.0.0.0") -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         EXPAND
> %{%{control:PacketFence-Tenant-Id}:-0}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:            --> 1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (
> "%{%{control:PacketFence-Tenant-Id}:-0}" == "0")  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (
> &control:PacketFence-Tenant-Id == 0 ) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (
> &control:PacketFence-Tenant-Id == 0 )  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # policy
> packetfence-set-tenant-id = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       update {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # update = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       policy
> packetfence-audit-log-reject {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name &&
> (&User-Name == "dummy")) {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         if (&User-Name &&
> (&User-Name == "dummy"))  -> FALSE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         else {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           policy request-timing
> {if (control:PacketFence-Request-Time != 0
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:             ) {
>
> (47157) Thu Feb 13 13:46:55 2020: ERROR:             Failed retrieving
> values required to evaluate condition
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           } # policy
> request-timing = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: sql_reject: EXPAND
> type.reject.query
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: sql_reject:    -->
> type.reject.query
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: sql_reject: Using query template
> 'query'
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: sql_reject: EXPAND %{User-Name}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: sql_reject:    -->
> MYDOMAIN\\myuser
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: sql_reject: SQL-User-Name set to
> 'MYDOMAIN\\myuser'
>
> (47157) Thu Feb 13 13:46:55 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}')
>
> (47157) Thu Feb 13 13:46:55 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               ( 'f0:1f:af:23:73:6d', '', 'N/A',
> 'MYDOMAIN=5Cmyuser',                'myuser', 'MYDOMAIN',
> 'Radius-Access-Request',                'N/A', 'N/A',
> 'N/A',                '1.1.1.1', '58:00:bb:37:ad:40',
> 'f0:1f:af:23:73:6d',                'Ethernet', '',
> 'ge-0/0/8.0',                'N/A', '564', 'N/A',                '1.1.1.1',
> 'LAB-4300-VC',  'Reject',                 'Failed retrieving values
> required to evaluate condition', '', '',                'N/A', 'N/A',
> 'N/A',                'N/A', '0', '0',                '', '', 'Realm =3D
> =22MYDOMAIN=22=2C NAS-Port =3D 564=2C PacketFence-Radius-Ip =3D
> =222.2.2.2=22=2C User-Name =3D =22MYDOMAIN=5C=5Cmyuser=22=2C
> FreeRADIUS-Proxied-To =3D 127.0.0.1=2C NAS-Port-Type =3D Ethernet=2C
> Acct-Session-Id =3D =228O2.1x810203cc00016034=22=2C Called-Station-Id =3D
> =2258:00:bb:37:ad:40=22=2C Event-Timestamp =3D =22Feb 13 2020 13:46:55
> EST=22=2C EAP-Message =3D 0x020700170144414946554b554e415c316a6c696e64656e=2C
> PacketFence-KeyBalanced =3D =22eb1f6320f59f6feba568d08011260431=22=2C
> NAS-IP-Address =3D 1.1.1.1=2C Stripped-User-Name =3D =22myuser=22=2C
> NAS-Port-Id =3D =22ge-0/0/8.0=22=2C NAS-Identifier =3D =22LAB-4300-VC=22=2C
> Calling-Station-Id =3D =22f0:1f:af:23:73:6d=22=2C User-Password =3D
> =22=2A=2A=2A=2A=2A=2A=22=2C Module-Failure-Message =3D =22Failed retrieving
> values required to evaluate condition=22=2C SQL-User-Name =3D
> =22MYDOMAIN=5C=5C=5C=5Cmyuser=22','', 'N/A', '1', '2.2.2.2')
>
> (47157) Thu Feb 13 13:46:55 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               ( 'f0:1f:af:23:73:6d', '', 'N/A',
> 'MYDOMAIN=5Cmyuser',                'myuser', 'MYDOMAIN',
> 'Radius-Access-Request',                'N/A', 'N/A',
> 'N/A',                '1.1.1.1', '58:00:bb:37:ad:40',
> 'f0:1f:af:23:73:6d',                'Ethernet', '',
> 'ge-0/0/8.0',                'N/A', '564', 'N/A',                '1.1.1.1',
> 'LAB-4300-VC',  'Reject',                 'Failed retrieving values
> required to evaluate condition', '', '',                'N/A', 'N/A',
> 'N/A',                'N/A', '0', '0',                '', '', 'Realm =3D
> =22MYDOMAIN=22=2C NAS-Port =3D 564=2C PacketFence-Radius-Ip =3D
> =222.2.2.2=22=2C User-Name =3D =22MYDOMAIN=5C=5Cmyuser=22=2C
> FreeRADIUS-Proxied-To =3D 127.0.0.1=2C NAS-Port-Type =3D Ethernet=2C
> Acct-Session-Id =3D =228O2.1x810203cc00016034=22=2C Called-Station-Id =3D
> =2258:00:bb:37:ad:40=22=2C Event-Timestamp =3D =22Feb 13 2020 13:46:55
> EST=22=2C EAP-Message =3D 0x020700170144414946554b554e415c316a6c696e64656e=2C
> PacketFence-KeyBalanced =3D =22eb1f6320f59f6feba568d08011260431=22=2C
> NAS-IP-Address =3D 1.1.1.1=2C Stripped-User-Name =3D =22myuser=22=2C
> NAS-Port-Id =3D =22ge-0/0/8.0=22=2C NAS-Identifier =3D =22LAB-4300-VC=22=2C
> Calling-Station-Id =3D =22f0:1f:af:23:73:6d=22=2C User-Password =3D
> =22=2A=2A=2A=2A=2A=2A=22=2C Module-Failure-Message =3D =22Failed retrieving
> values required to evaluate condition=22=2C SQL-User-Name =3D
> =22MYDOMAIN=5C=5C=5C=5Cmyuser=22','', 'N/A', '1', '2.2.2.2')
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: sql_reject: SQL query returned:
> success
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: sql_reject: 1 record(s) updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:           [sql_reject] = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:         } # else = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # policy
> packetfence-audit-log-reject = ok
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: attr_filter.access_reject: EXPAND
> %{User-Name}
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: attr_filter.access_reject:    -->
> MYDOMAIN\\myuser
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: attr_filter.access_reject:
> Matched entry DEFAULT at line 11
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       [attr_filter.access_reject]
> = updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       update outer.session-state {
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:       } # update
> outer.session-state = noop
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     } # Post-Auth-Type REJECT =
> updated
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: } # server packetfence-tunnel
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: Virtual server sending reply
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Got tunneled reply code
> 3
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: Tunneled authentication
> was rejected
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap_peap: FAILURE
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap: Sending EAP Request (code 1)
> ID 8 length 46
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: eap: EAP session adding
> &reply:State = 0xa7aca802a0a4b173
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:     [eap] = handled
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   } # authenticate = handled
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: Using Post-Auth-Type Challenge
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: Post-Auth-Type sub-section not
> found.  Ignoring.
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: # Executing group from file
> /usr/local/pf/raddb/sites-enabled/packetfence
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: session-state: Saving cached
> attributes
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   TLS-Session-Cipher-Suite =
> "ECDHE-RSA-AES256-GCM-SHA384"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   TLS-Session-Version = "TLS 1.2"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Module-Failure-Message :=
> "Failed retrieving values required to evaluate condition"
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: Sent Access-Challenge Id 50 from
> 2.2.2.2:1812 to 1.1.1.1:62346 length 0
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   EAP-Message =
> 0x0108002e1900170303002326d6be811a8da5a14f28fc850dced4a1020a
> 4298af6952d59d739bc90373465deb811f
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   Message-Authenticator =
> 0x00000000000000000000000000000000
>
> (47157) Thu Feb 13 13:46:55 2020: Debug:   State =
> 0xa7aca802a0a4b1731d68285805a095a1
>
> (47157) Thu Feb 13 13:46:55 2020: Debug: Finished request
>
>
> PRIVACY NOTICE: The information contained in this e-mail, including any
> attachments, is confidential and intended only for the named recipient(s).
> Unauthorized use, disclosure, forwarding, or copying is strictly prohibited
> and may be unlawful. If you are not the intended recipient, please delete
> the e-mail and any attachments and notify us immediately by return e-mail.
>
_______________________________________________
PacketFence-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/packetfence-users

Reply via email to