Hello mailing list,

I have installed a fresh Packetfence 6.4.0-1 on Centos 7.3.1611 for testing

Test switch is a Cisco 2960 running 15.0(1)SE3

PF is configured for registration vlan 820

When I manually configure a port on the test switch to vlan 820 I can
access the portal from PF

I configured the switchport for MAB from Packetfence and Cisco documentation

With aaa and radius debug enabled, I can see radius authentication
starting, the port being set to vlan 820, then immediately failing
authorization and starting again. This loops forever until the port is
shut, or until I register the mac address in the PF Administration console,
at which point a production  VLAN is allocated as expected.

While the looping is going on, the Registration VLAN never stays configured
on the port long enough for the workstation to get an IP and reach the
guest portal

When radiusd -X is run, an access-accept message is sent, and the process
loops every time the switch loops.

otherwise, I can never get the guest portal, and the logs fill up
incredibly quickly just from one port.

Does anyone have any suggestions? I primarily suspect my switch config is
faulty or missing some key element...

SWITCH CONFIG:

aaa new-model

aaa group server radius pf
 server name SVVNMS03
 ip radius source-interface Vlan100

aaa authentication dot1x default group pf
aaa authorization network default group pf

aaa server radius dynamic-author
 client 10.216.9.72 server-key 7 XXXXXXXXXXXXXXXXXXXXXXXX
 port 3799

interface FastEthernet0/2
 description MAB-NO-VOIP
 switchport mode access
 logging event link-status
 authentication order mab
 authentication priority mab
 authentication port-control auto
 authentication periodic
 authentication timer restart 10800
 authentication timer reauthenticate 10800
 mab
 no snmp trap link-status
 dot1x pae authenticator
 dot1x timeout quiet-period 2
 dot1x timeout tx-period 3
 spanning-tree portfast
 spanning-tree bpduguard enable

radius-server retransmit 1
radius-server timeout 2
radius-server vsa send authentication

radius server SVVNMS03
 address ipv4 10.216.9.72 auth-port 1812 acct-port 1813
 timeout 2
 retransmit 1
 key 7 XXXXXXXXXXXXXXXXXXXXXXXX
=====================================

SWITCH DEBUG:

Feb  1 18:05:39.072 GMT: AAA/BIND(0000004B): Bind i/f
Feb  1 18:05:39.072 GMT: AAA/ACCT/HC(0000004B): Register Dot1X/5400003F 64
bit counter support not configured
Feb  1 18:05:39.072 GMT: AAA/ACCT/HC(0000004B): Update Dot1X/5400003F
Feb  1 18:05:39.072 GMT: AAA/ACCT/HC(0000004B): no HC Dot1X/5400003F
Feb  1 18:05:39.072 GMT: AAA/ACCT/EVENT/(0000004B): CALL START
Feb  1 18:05:39.072 GMT: Getting session id for NET(0000004B) : db=39078C4
Feb  1 18:05:39.072 GMT: AAA/ACCT(00000000): add node, session 65
Feb  1 18:05:39.072 GMT: AAA/ACCT/NET(0000004B): add, count 1
Feb  1 18:05:39.072 GMT: Getting session id for NET(0000004B) : db=39078C4
Feb  1 18:05:39.400 GMT: %AUTHMGR-5-START: Starting 'mab' for client
(40a8.f0a9.e051) on Interface Fa0/2 AuditSessionID 0AD800A70000003E00125D6B
Feb  1 18:05:39.400 GMT: AAA/AUTHEN/8021X (0000004B): Pick method list
'default'
Feb  1 18:05:39.400 GMT: RADIUS/ENCODE(0000004B):Orig. component type =
Dot1X
Feb  1 18:05:39.400 GMT: RADIUS/ENCODE(0000004B): Unsupported AAA attribute
hwidb
Feb  1 18:05:39.400 GMT: RADIUS/ENCODE(0000004B): Unsupported AAA attribute
auth-profile
Feb  1 18:05:39.400 GMT: RADIUS(0000004B): Config NAS IP: 10.216.0.167
Feb  1 18:05:39.400 GMT: RADIUS(0000004B): Config NAS IPv6: ::
Feb  1 18:05:39.400 GMT: Getting session id for DOT1X(0000004B) : db=39078C4
Feb  1 18:05:39.400 GMT: RADIUS/ENCODE(0000004B): acct_session_id: 65
Feb  1 18:05:39.400 GMT: RADIUS(0000004B): sending
Feb  1 18:05:39.400 GMT: RADIUS(0000004B): Send Access-Request to
10.216.9.72:1812 id 1645/60, len 237
Feb  1 18:05:39.400 GMT: RADIUS:  authenticator B4 28 20 EC F8 7C B8 2A -
47 C0 78 E6 3B 63 CB E1
Feb  1 18:05:39.400 GMT: RADIUS:  User-Name           [1]   14
"40a8f0a9e051"
Feb  1 18:05:39.400 GMT: RADIUS:  User-Password       [2]   18  *
Feb  1 18:05:39.400 GMT: RADIUS:  Service-Type        [6]   6   Call
Check                [10]
Feb  1 18:05:39.400 GMT: RADIUS:  Vendor, Cisco       [26]  31
Feb  1 18:05:39.400 GMT: RADIUS:   Cisco AVpair       [1]   25
"service-type=Call Check"
Feb  1 18:05:39.400 GMT: RADIUS:  Framed-MTU          [12]  6
1500
Feb  1 18:05:39.400 GMT: RADIUS:  Called-Station-Id   [30]  19
"30-37-A6-7E-82-82"
Feb  1 18:05:39.400 GMT: RADIUS:  Calling-Station-Id  [31]  19
"40-A8-F0-A9-E0-51"
Feb  1 18:05:39.408 GMT: RADIUS:  Message-Authenticato[80]  18
Feb  1 18:05:39.408 GMT: RADIUS:   59 05 27 15 EB D2 EF 21 00 97 C8 79 9B
29 2E DE            [ Y'!y).]
Feb  1 18:05:39.408 GMT: RADIUS:  EAP-Key-Name        [102] 2   *
Feb  1 18:05:39.408 GMT: RADIUS:  Vendor, Cisco       [26]  49
Feb  1 18:05:39.408 GMT: RADIUS:   Cisco AVpair       [1]   43
"audit-session-id=0AD800A70000003E00125D6B"
Feb  1 18:05:39.408 GMT: RADIUS:  NAS-Port-Type       [61]  6
Ethernet                  [15]
Feb  1 18:05:39.408 GMT: RADIUS:  NAS-Port            [5]   6
50002
Feb  1 18:05:39.408 GMT: RADIUS:  NAS-Port-Id         [87]  17
"FastEthernet0/2"
Feb  1 18:05:39.408 GMT: RADIUS:  NAS-IP-Address      [4]   6
10.216.0.167
Feb  1 18:05:39.408 GMT: RADIUS(0000004B): Sending a IPv4 Radius Packet
Feb  1 18:05:39.408 GMT: RADIUS(0000004B): Started 2 sec timeout
Feb  1 18:05:39.433 GMT: RADIUS: Received from id 1645/60 10.216.9.72:1812,
Access-Accept, len 67
Feb  1 18:05:39.433 GMT: RADIUS:  authenticator 20 58 F8 39 9F 12 BD A9 -
E1 E5 BE 66 EE 73 CE F9
Feb  1 18:05:39.433 GMT: RADIUS:  Tunnel-Type         [64]  6
00:VLAN                   [13]
Feb  1 18:05:39.433 GMT: RADIUS:  Tunnel-Private-Group[81]  5   "820"
Feb  1 18:05:39.433 GMT: RADIUS:  Filter-Id           [11]  17
Feb  1 18:05:39.433 GMT: RADIUS:   72 65 67 69 73 74 72 61 74 69 6F 6E 2E
69 6E   [ registration.in]
Feb  1 18:05:39.433 GMT: RADIUS:  Tunnel-Medium-Type  [65]  6
00:ALL_802                [6]
Feb  1 18:05:39.433 GMT: RADIUS:  Vendor, Unknown     [26]  13
Feb  1 18:05:39.433 GMT: RADIUS:  Session-Timeout     [27]  7
Feb  1 18:05:39.433 GMT: RADIUS:   61 6C 6C 6F 77             [ allow]
Feb  1 18:05:39.433 GMT: RADIUS(0000004B): Received from id 1645/60
Feb  1 18:05:39.433 GMT: %MAB-5-SUCCESS: Authentication successful for
client (40a8.f0a9.e051) on Interface Fa0/2 AuditSessionID
0AD800A70000003E00125D6B
Feb  1 18:05:39.433 GMT: %AUTHMGR-7-RESULT: Authentication result 'success'
from 'mab' for client (40a8.f0a9.e051) on Interface Fa0/2 AuditSessionID
0AD800A70000003E00125D6B
Feb  1 18:05:39.433 GMT: %AUTHMGR-5-VLANASSIGN: VLAN 820 assigned to
Interface Fa0/2 AuditSessionID 0AD800A70000003E00125D6B
Feb  1 18:05:39.467 GMT: %AUTHMGR-5-FAIL: Authorization failed for client
(40a8.f0a9.e051) on Interface Fa0/2 AuditSessionID 0AD800A70000003E00125D6B
Feb  1 18:05:39.467 GMT: AUTH-SYNC (Fa0/2) Syncing update for context
(40a8.f0a9.e051)
Feb  1 18:05:39.509 GMT: AUTH-SYNC (Fa0/2) Syncing delete for context
(40a8.f0a9.e051)
Feb  1 18:05:39.509 GMT: AAA/ACCT/HC(0000004B): Update Dot1X/5400003F
Feb  1 18:05:39.509 GMT: AAA/ACCT/HC(0000004B): no HC Dot1X/5400003F
Feb  1 18:05:39.509 GMT: AAA/ACCT/HC(0000004B): Update Dot1X/5400003F
Feb  1 18:05:39.509 GMT: AAA/ACCT/HC(0000004B): no HC Dot1X/5400003F
Feb  1 18:05:39.517 GMT: AAA/ACCT/EVENT/(0000004B): CALL STOP
Feb  1 18:05:39.517 GMT: AAA/ACCT/CALL STOP(0000004B): Sending stop requests
Feb  1 18:05:39.517 GMT: AAA/ACCT(0000004B): Send all stops
Feb  1 18:05:39.517 GMT: AAA/ACCT/NET(0000004B): STOP
Feb  1 18:05:39.517 GMT: AAA/ACCT/NET(0000004B): Method list not found
Feb  1 18:05:39.517 GMT: AAA/ACCT(0000004B): del node, session 65
Feb  1 18:05:39.517 GMT: AAA/ACCT/NET(0000004B): free_rec, count 0
Feb  1 18:05:39.517 GMT: /AAA/ACCTNET(0000004B) reccnt 0, csr TRUE, osr 0
Feb  1 18:05:39.517 GMT: AAA/ACCT/NET(0000004B): Last rec in db, intf not
enqueued
Feb  1 18:05:39.718 GMT: AAA/BIND(0000004C): Bind i/f
***this continues to loop as above

======================================

RADIUSD DEBUG

Listening on auth address 127.0.0.1 port 1812 bound to server packetfence
Listening on auth address 10.216.9.72 port 1812 bound to server packetfence
Listening on command file /usr/local/pf/var/run/radiusd.sock
Listening on proxy address * port 39363
Ready to process requests
(0) Received Access-Request Id 35 from 10.216.0.167:1645 to 10.216.9.72:1812
length 237
(0)   User-Name = "40a8f0a9e051"
(0)   User-Password = "40a8f0a9e051"
(0)   Service-Type = Call-Check
(0)   Cisco-AVPair = "service-type=Call Check"
(0)   Framed-MTU = 1500
(0)   Called-Station-Id = "30-37-A6-7E-82-82"
(0)   Calling-Station-Id = "40-A8-F0-A9-E0-51"
(0)   Message-Authenticator = 0x2f390957e15d061946d59dd43a49016c
(0)   Cisco-AVPair = "audit-session-id=0AD800A700000023000A2070"
(0)   NAS-Port-Type = Ethernet
(0)   NAS-Port = 50002
(0)   NAS-Port-Id = "FastEthernet0/2"
(0)   NAS-IP-Address = 10.216.0.167
(0) # Executing section authorize from file raddb//sites-enabled/packetfence
(0)   authorize {
(0)     update {
(0)       EXPAND %{Packet-Src-IP-Address}
(0)          --> 10.216.0.167
(0)       &request:FreeRADIUS-Client-IP-Address := 10.216.0.167
(0)       &control:PacketFence-RPC-Server = 127.0.0.1
(0)       &control:PacketFence-RPC-Port = 7070
(0)       &control:PacketFence-RPC-User =
(0)       &control:PacketFence-RPC-Pass =
(0)       &control:PacketFence-RPC-Proto = http
(0)       EXPAND %l
(0)          --> 1485971799
(0)       &control:Tmp-Integer-0 := 1485971799
(0)       &control:PacketFence-Request-Time := 0
(0)     } # update = noop
(0)     policy rewrite_calling_station_id {
(0)       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))
{
(0)       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
(0)       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))
{
(0)         update request {
(0)           EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(0)              --> 40:a8:f0:a9:e0:51
(0)           &Calling-Station-Id := 40:a8:f0:a9:e0:51
(0)         } # update request = noop
(0)         [updated] = updated
(0)       } # 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
(0)       ... skipping else: Preceding "if" was taken
(0)     } # policy rewrite_calling_station_id = updated
(0)     policy rewrite_called_station_id {
(0)       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))
{
(0)       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
(0)       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))
{
(0)         update request {
(0)           &Called-Station-Id !* ANY
(0)           EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(0)              --> 30:37:a6:7e:82:82
(0)           &Called-Station-Id := 30:37:a6:7e:82:82
(0)         } # update request = noop
(0)         if ("%{8}") {
(0)         EXPAND %{8}
(0)            -->
(0)         if ("%{8}")  -> FALSE
(0)         elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~
/^ssid=(.*)$/i) {
(0)         elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~
/^ssid=(.*)$/i)  -> FALSE
(0)         elsif (Aruba-Essid-Name) {
(0)         elsif (Aruba-Essid-Name)  -> FALSE
(0)         elsif ( (Cisco-AVPair)  && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i)
{
(0)         EXPAND %{Cisco-AVPair}
(0)            --> service-type=Call Check
(0)         elsif ( (Cisco-AVPair)  && "%{Cisco-AVPair}" =~
/^ssid=(.*)$/i)  -> FALSE
(0)         [updated] = updated
(0)       } # 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
(0)       ... skipping else: Preceding "if" was taken
(0)     } # policy rewrite_called_station_id = updated
(0)     policy filter_username {
(0)       if (&User-Name) {
(0)       if (&User-Name)  -> TRUE
(0)       if (&User-Name)  {
(0)         if (&User-Name =~ / /) {
(0)         if (&User-Name =~ / /)  -> FALSE
(0)         if (&User-Name =~ /@[^@]*@/ ) {
(0)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(0)         if (&User-Name =~ /\.\./ ) {
(0)         if (&User-Name =~ /\.\./ )  -> FALSE
(0)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(0)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   ->
FALSE
(0)         if (&User-Name =~ /\.$/)  {
(0)         if (&User-Name =~ /\.$/)   -> FALSE
(0)         if (&User-Name =~ /@\./)  {
(0)         if (&User-Name =~ /@\./)   -> FALSE
(0)       } # if (&User-Name)  = updated
(0)     } # policy filter_username = updated
(0)     policy filter_password {
(0)       if (&User-Password &&    (&User-Password !=
"%{string:User-Password}")) {
(0)       EXPAND %{string:User-Password}
(0)          --> 40a8f0a9e051
(0)       if (&User-Password &&    (&User-Password !=
"%{string:User-Password}"))  -> FALSE
(0)     } # policy filter_password = updated
(0)     [preprocess] = ok
(0) suffix: Checking for suffix after "@"
(0) suffix: No '@' in User-Name = "40a8f0a9e051", skipping NULL due to
config.
(0)     [suffix] = noop
(0) ntdomain: Checking for prefix before "\"
(0) ntdomain: No '\' in User-Name = "40a8f0a9e051", looking up realm NULL
(0) ntdomain: Found realm "null"
(0) ntdomain: Adding Stripped-User-Name = "40a8f0a9e051"
(0) ntdomain: Adding Realm = "null"
(0) ntdomain: Authentication realm is LOCAL
(0)     [ntdomain] = ok
(0) eap: No EAP-Message, not doing EAP
(0)     [eap] = noop
(0)     if ( !EAP-Message ) {
(0)     if ( !EAP-Message )  -> TRUE
(0)     if ( !EAP-Message )  {
(0)       update {
(0)         &control:Auth-Type := Accept
(0)       } # update = noop
(0)     } # if ( !EAP-Message )  = noop
(0)     policy packetfence-eap-mac-policy {
(0)       if ( &EAP-Type ) {
(0)       if ( &EAP-Type )  -> FALSE
(0)       [noop] = noop
(0)     } # policy packetfence-eap-mac-policy = noop
(0) pap: WARNING:
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
(0) pap: WARNING: !!! Ignoring control:User-Password.  Update your
!!!
(0) pap: WARNING: !!! configuration so that the "known good" clear text !!!
(0) pap: WARNING: !!! password is in Cleartext-Password and NOT in
!!!
(0) pap: WARNING: !!! User-Password.
!!!
(0) pap: WARNING:
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
(0) pap: WARNING: Auth-Type already set.  Not setting to PAP
(0)     [pap] = noop
(0)   } # authorize = updated
(0) Found Auth-Type = Accept
(0) Auth-Type = Accept, accepting the user
(0) # Executing section post-auth from file raddb//sites-enabled/packetfence
(0)   post-auth {
(0)     update {
(0)       EXPAND %{Packet-Src-IP-Address}
(0)          --> 10.216.0.167
(0)       &request:FreeRADIUS-Client-IP-Address := 10.216.0.167
(0)       &control:PacketFence-RPC-Server = 127.0.0.1
(0)       &control:PacketFence-RPC-Port = 7070
(0)       &control:PacketFence-RPC-User =
(0)       &control:PacketFence-RPC-Pass =
(0)       &control:PacketFence-RPC-Proto = http
(0)     } # update = noop
(0)     if (! EAP-Type || (EAP-Type != TTLS  && EAP-Type != PEAP) ) {
(0)     if (! EAP-Type || (EAP-Type != TTLS  && EAP-Type != PEAP) )  -> TRUE
(0)     if (! EAP-Type || (EAP-Type != TTLS  && EAP-Type != PEAP) )  {
rlm_rest (rest): Reserved connection (0)
(0) rest: Expanding URI components
(0) rest: EXPAND http://127.0.0.1:7070
(0) rest:    --> http://127.0.0.1:7070
(0) rest: EXPAND //radius/rest/authorize
(0) rest:    --> //radius/rest/authorize
(0) rest: Sending HTTP POST to "http://127.0.0.1:7070//radius/rest/authorize
"
(0) rest: Encoding attribute "User-Name"
(0) rest: Encoding attribute "User-Password"
(0) rest: Encoding attribute "NAS-IP-Address"
(0) rest: Encoding attribute "NAS-Port"
(0) rest: Encoding attribute "Service-Type"
(0) rest: Encoding attribute "Framed-MTU"
(0) rest: Encoding attribute "Called-Station-Id"
(0) rest: Encoding attribute "Calling-Station-Id"
(0) rest: Encoding attribute "NAS-Port-Type"
(0) rest: Encoding attribute "Event-Timestamp"
(0) rest: Encoding attribute "Message-Authenticator"
(0) rest: Encoding attribute "NAS-Port-Id"
(0) rest: Encoding attribute "Cisco-AVPair"
(0) rest: Encoding attribute "Stripped-User-Name"
(0) rest: Encoding attribute "Realm"
(0) rest: Encoding attribute "FreeRADIUS-Client-IP-Address"
(0) rest: Processing response header
(0) rest:   Status : 200 (OK)
(0) rest:   Type   : json (application/json)
(0) rest: Parsing attribute "control:PacketFence-Role"
(0) rest: EXPAND registration
(0) rest:    --> registration
(0) rest: PacketFence-Role := "registration"
(0) rest: Parsing attribute "control:PacketFence-Eap-Type"
(0) rest: EXPAND 0
(0) rest:    --> 0
(0) rest: PacketFence-Eap-Type := "0"
(0) rest: Parsing attribute "Tunnel-Type"
(0) rest: EXPAND 13
(0) rest:    --> 13
(0) rest: Tunnel-Type := VLAN
(0) rest: Parsing attribute "control:PacketFence-AutoReg"
(0) rest: EXPAND 0
(0) rest:    --> 0
(0) rest: PacketFence-AutoReg := "0"
(0) rest: Parsing attribute "Tunnel-Private-Group-ID"
(0) rest: EXPAND 820
(0) rest:    --> 820
(0) rest: Tunnel-Private-Group-Id := "820"
(0) rest: Parsing attribute "control:PacketFence-Request-Time"
(0) rest: EXPAND 1485971799
(0) rest:    --> 1485971799
(0) rest: PacketFence-Request-Time := 1485971799
(0) rest: Parsing attribute "control:PacketFence-Switch-Ip-Address"
(0) rest: EXPAND 10.216.0.167
(0) rest:    --> 10.216.0.167
(0) rest: PacketFence-Switch-Ip-Address := "10.216.0.167"
(0) rest: Parsing attribute "control:PacketFence-UserName"
(0) rest: EXPAND 40a8f0a9e051
(0) rest:    --> 40a8f0a9e051
(0) rest: PacketFence-UserName := "40a8f0a9e051"
(0) rest: Parsing attribute "control:PacketFence-IsPhone"
(0) rest: PacketFence-IsPhone := ""
(0) rest: Parsing attribute "control:PacketFence-Switch-Mac"
(0) rest: EXPAND 30:37:a6:7e:82:82
(0) rest:    --> 30:37:a6:7e:82:82
(0) rest: PacketFence-Switch-Mac := "30:37:a6:7e:82:82"
(0) rest: Parsing attribute "control:PacketFence-Switch-Id"
(0) rest: EXPAND 10.216.0.167
(0) rest:    --> 10.216.0.167
(0) rest: PacketFence-Switch-Id := "10.216.0.167"
(0) rest: Parsing attribute "Filter-Id"
(0) rest: EXPAND registration.in
(0) rest:    --> registration.in
(0) rest: Filter-Id := "registration.in"
(0) rest: Parsing attribute "Tunnel-Medium-Type"
(0) rest: EXPAND 6
(0) rest:    --> 6
(0) rest: Tunnel-Medium-Type := IEEE-802
(0) rest: Parsing attribute "control:PacketFence-Computer-Name"
(0) rest: EXPAND RXHD03099
(0) rest:    --> RXHD03099
(0) rest: PacketFence-Computer-Name := "RXHD03099"
(0) rest: Parsing attribute "Cisco-AVPair"
(0) rest: WARNING: Zero length value array, skipping...
(0) rest: Parsing attribute "control:PacketFence-Mac"
(0) rest: EXPAND 40:a8:f0:a9:e0:51
(0) rest:    --> 40:a8:f0:a9:e0:51
(0) rest: PacketFence-Mac := "40:a8:f0:a9:e0:51"
(0) rest: Parsing attribute "control:PacketFence-IfIndex"
(0) rest: EXPAND 10002
(0) rest:    --> 10002
(0) rest: PacketFence-IfIndex := "10002"
(0) rest: Parsing attribute "reply:PacketFence-Authorization-Status"
(0) rest: EXPAND allow
(0) rest:    --> allow
(0) rest: PacketFence-Authorization-Status := "allow"
(0) rest: Parsing attribute "control:PacketFence-Connection-Type"
(0) rest: EXPAND WIRED_MAC_AUTH
(0) rest:    --> WIRED_MAC_AUTH
(0) rest: PacketFence-Connection-Type := "WIRED_MAC_AUTH"
(0) rest: Parsing attribute "control:PacketFence-Status"
(0) rest: EXPAND unreg
(0) rest:    --> unreg
(0) rest: PacketFence-Status := "unreg"
rlm_rest (rest): Released connection (0)
rlm_rest (rest): Need 5 more connections to reach 10 spares
rlm_rest (rest): Opening additional connection (5), 1 of 59 pending slots
used
rlm_rest (rest): Connecting to "http://127.0.0.1:7070/";
(0)       [rest] = updated
(0)       if (&reply:PacketFence-Authorization-Status == "deny") {
(0)       if (&reply:PacketFence-Authorization-Status == "deny")  -> FALSE
(0)       else {
(0)         policy packetfence-audit-log-accept {
(0)           if (&User-Name != "dummy") {
(0)           if (&User-Name != "dummy")  -> TRUE
(0)           if (&User-Name != "dummy")  {
(0)             policy request-timing {
(0)               if (control:PacketFence-Request-Time != 0) {
(0)               if (control:PacketFence-Request-Time != 0)  -> TRUE
(0)               if (control:PacketFence-Request-Time != 0)  {
(0)                 update control {
(0)                   EXPAND %{expr: %{control:PacketFence-Request-Time} -
%{control:Tmp-Integer-0}}
(0)                      --> 0
(0)                   &PacketFence-Request-Time := 0
(0)                 } # update control = noop
(0)               } # if (control:PacketFence-Request-Time != 0)  = noop
(0)             } # policy request-timing = noop
(0) sql: EXPAND type.accept.query
(0) sql:    --> type.accept.query
(0) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (1)
(0) sql: EXPAND %{User-Name}
(0) sql:    --> 40a8f0a9e051
(0) sql: SQL-User-Name set to '40a8f0a9e051'
(0) sql: 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)              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}',
'Accept',                '%{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}:-N/A}',
'%{%{control:PacketFence-IsPhone}:-N/A}',
'%{request:PacketFence-Domain}', '',
'%{pairs:&request:[*]}','%{pairs:&reply:[*]}',
'%{control:PacketFence-Request-Time}')
(0) sql:    --> 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)              VALUES               (
'40:a8:f0:a9:e0:51', '', 'RXHD03099', '40a8f0a9e051',
'40a8f0a9e051', 'null', 'Radius-Access-Request',
'10.216.0.167', '30:37:a6:7e:82:82', '10.216.0.167',
'10.216.0.167', '30:37:a6:7e:82:82', '40:a8:f0:a9:e0:51',
'Ethernet', '', 'FastEthernet0/2',                '10002', '50002',
'WIRED_MAC_AUTH',                '10.216.0.167', '',
'Accept',                '', 'Accept', '',                'registration',
'unreg', 'N/A',                'N/A', '0', 'N/A',                '', '',
'User-Name =3D =2240a8f0a9e051=22=2C User-Password =3D
=2240a8f0a9e051=22=2C NAS-IP-Address =3D 10.216.0.167=2C NAS-Port =3D
50002=2C Service-Type =3D Call-Check=2C Framed-MTU =3D 1500=2C
Called-Station-Id =3D =2230:37:a6:7e:82:82=22=2C Calling-Station-Id =3D
=2240:a8:f0:a9:e0:51=22=2C NAS-Port-Type =3D Ethernet=2C Event-Timestamp
=3D =22Feb  1 2017 17:56:39 GMT=22=2C Message-Authenticator =3D
0x2f390957e15d061946d59dd43a49016c=2C NAS-Port-Id =3D
=22FastEthernet0/2=22=2C Cisco-AVPair =3D =22service-type=3DCall
Check=22=2C Cisco-AVPair =3D
=22audit-session-id=3D0AD800A700000023000A2070=22=2C Stripped-User-Name =3D
=2240a8f0a9e051=22=2C Realm =3D =22null=22=2C FreeRADIUS-Client-IP-Address
=3D 10.216.0.167=2C SQL-User-Name =3D =2240a8f0a9e051=22','Tunnel-Type =3D
VLAN=2C Tunnel-Private-Group-Id =3D =22820=22=2C Filter-Id =3D =
22registration.in=22=2C Tunnel-Medium-Type =3D IEEE-802=2C
PacketFence-Authorization-Status =3D =22allow=22', '0')
(0) sql: 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)              VALUES               (
'40:a8:f0:a9:e0:51', '', 'RXHD03099', '40a8f0a9e051',
'40a8f0a9e051', 'null', 'Radius-Access-Request',
'10.216.0.167', '30:37:a6:7e:82:82', '10.216.0.167',
'10.216.0.167', '30:37:a6:7e:82:82', '40:a8:f0:a9:e0:51',
'Ethernet', '', 'FastEthernet0/2',                '10002', '50002',
'WIRED_MAC_AUTH',                '10.216.0.167', '',
'Accept',                '', 'Accept', '',                'registration',
'unreg', 'N/A',                'N/A', '0', 'N/A',                '', '',
'User-Name =3D =2240a8f0a9e051=22=2C User-Password =3D
=2240a8f0a9e051=22=2C NAS-IP-Address =3D 10.216.0.167=2C NAS-Port =3D
50002=2C Service-Type =3D Call-Check=2C Framed-MTU =3D 1500=2C
Called-Station-Id =3D =2230:37:a6:7e:82:82=22=2C Calling-Station-Id =3D
=2240:a8:f0:a9:e0:51=22=2C NAS-Port-Type =3D Ethernet=2C Event-Timestamp
=3D =22Feb  1 2017 17:56:39 GMT=22=2C Message-Authenticator =3D
0x2f390957e15d061946d59dd43a49016c=2C NAS-Port-Id =3D
=22FastEthernet0/2=22=2C Cisco-AVPair =3D =22service-type=3DCall
Check=22=2C Cisco-AVPair =3D
=22audit-session-id=3D0AD800A700000023000A2070=22=2C Stripped-User-Name =3D
=2240a8f0a9e051=22=2C Realm =3D =22null=22=2C FreeRADIUS-Client-IP-Address
=3D 10.216.0.167=2C SQL-User-Name =3D =2240a8f0a9e051=22','Tunnel-Type =3D
VLAN=2C Tunnel-Private-Group-Id =3D =22820=22=2C Filter-Id =3D =
22registration.in=22=2C Tunnel-Medium-Type =3D IEEE-802=2C
PacketFence-Authorization-Status =3D =22allow=22', '0')
(0) sql: SQL query returned: success
(0) sql: 1 record(s) updated
rlm_sql (sql): Released connection (1)
rlm_sql (sql): Need 4 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (6), 1 of 58 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'pf' on Localhost via UNIX socket,
server version 5.5.52-MariaDB, protocol version 10
(0)             [sql] = ok
(0)           } # if (&User-Name != "dummy")  = ok
(0)         } # policy packetfence-audit-log-accept = ok
(0)       } # else = ok
(0)     } # if (! EAP-Type || (EAP-Type != TTLS  && EAP-Type != PEAP) )  =
updated
(0) attr_filter.packetfence_post_auth: EXPAND %{User-Name}
(0) attr_filter.packetfence_post_auth:    --> 40a8f0a9e051
(0) attr_filter.packetfence_post_auth: Matched entry DEFAULT at line 10
(0)     [attr_filter.packetfence_post_auth] = updated
(0) linelog: EXPAND messages.%{%{reply:Packet-Type}:-default}
(0) linelog:    --> messages.Access-Accept
(0) linelog: EXPAND %t : [mac:%{Calling-Station-Id}] Accepted user:
%{reply:User-Name} and returned VLAN %{reply:Tunnel-Private-Group-ID}
(0) linelog:    --> Wed Feb  1 17:56:39 2017 : [mac:40:a8:f0:a9:e0:51]
Accepted user:  and returned VLAN 820
(0) linelog: EXPAND /usr/local/pf/logs/radius.log
(0) linelog:    --> /usr/local/pf/logs/radius.log
(0)     [linelog] = ok
(0)   } # post-auth = updated
(0) Login OK: [40a8f0a9e051] (from client 10.216.0.167 port 50002 cli
40:a8:f0:a9:e0:51)
(0) Sent Access-Accept Id 35 from 10.216.9.72:1812 to 10.216.0.167:1645
length 0
(0)   Tunnel-Type = VLAN
(0)   Tunnel-Private-Group-Id = "820"
(0)   Filter-Id = "registration.in"
(0)   Tunnel-Medium-Type = IEEE-802
(0)   PacketFence-Authorization-Status = "allow"
(0) Finished request
Waking up in 4.9 seconds.

***This continues to loop as above
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, SlashDot.org! http://sdm.link/slashdot
_______________________________________________
PacketFence-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/packetfence-users

Reply via email to