Hi Fabrice,
We tried to uncheck the box "locationlog Close On Accounting Stop",
and restarted packetfence, but found the users are still stuck in
registration VLAN.
The queue count was zero at the moment.
We got the mysql output during each steps in the registration process.
1. When user connects to WiFi, there was a new locationlog, end_time
is 0000-00-00 00:00:00.
2. After user go to captive portal, before doing any authentication,
the locationlog was changed with end_time marked. (Does it mean the
locationlog was closed here?)
3. And right after authentication, no new locationlog and no change to
existing locationlog.
Warning messages "Can't re-evaluate access because no open locationlog
entry was found" shown in log
4. We let the device connected to WiFi, and after few minutes, the
device is moved to the working VLAN, a new locationlog shown, end_time
is 0000-00-00 00:00:00.
### right after user connects to WiFi
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
| mac | switch | port | vlan | role |
connection_type | connection_sub_type | dot1x_username | ssid
| start_time | end_time | switch_ip |
switch_mac | stripped_user_name | realm | session_id |
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
| 7c:04:00:11:22:33 | 172.18.4.61 | 0 | 501 | registration |
Wireless-802.11-NoEAP | NULL | 7c:04:00:11:22:33 |
SSID_A | 2018-01-23 11:31:32 | 0000-00-00 00:00:00 | 172.18.4.61 |
84:18:3a:aa:bb:cc | 7c:04:00:11:22:33 | null | NULL |
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
### after User goes to captive portal, before authentication
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
| mac | switch | port | vlan | role |
connection_type | connection_sub_type | dot1x_username | ssid
| start_time | end_time | switch_ip |
switch_mac | stripped_user_name | realm | session_id |
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
| 7c:04:00:11:22:33 | 172.18.4.61 | 0 | 501 | registration |
Wireless-802.11-NoEAP | NULL | 7c:04:00:11:22:33 |
SSID_A | 2018-01-23 11:31:32 | 2018-01-23 11:32:10 | 172.18.4.61 |
84:18:3a:aa:bb:cc | 7c:04:00:11:22:33 | null | NULL |
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
### right after authentication, User stuck in registration vlan, no
new locationlog entry
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
| mac | switch | port | vlan | role |
connection_type | connection_sub_type | dot1x_username | ssid
| start_time | end_time | switch_ip |
switch_mac | stripped_user_name | realm | session_id |
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
| 7c:04:00:11:22:33 | 172.18.4.61 | 0 | 501 | registration |
Wireless-802.11-NoEAP | NULL | 7c:04:00:11:22:33 |
SSID_A | 2018-01-23 11:31:32 | 2018-01-23 11:32:10 | 172.18.4.61 |
84:18:3a:aa:bb:cc | 7c:04:00:11:22:33 | null | NULL |
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
### after few minutes, User is moved to working vlan
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
| mac | switch | port | vlan | role |
connection_type | connection_sub_type | dot1x_username | ssid
| start_time | end_time | switch_ip |
switch_mac | stripped_user_name | realm | session_id |
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
| 7c:04:00:11:22:33 | 172.18.4.61 | 0 | 50 | role-staff |
Wireless-802.11-NoEAP | NULL | 7c:04:00:11:22:33 |
SSID_A | 2018-01-23 11:41:09 | 0000-00-00 00:00:00 | 172.18.4.61
| 84:18:3a:aa:bb:cc | 7c:04:00:11:22:33 | null | NULL |
| 7c:04:00:11:22:33 | 172.18.4.61 | 0 | 501 | registration |
Wireless-802.11-NoEAP | NULL | 7c:04:00:11:22:33 |
SSID_A | 2018-01-23 11:31:32 | 2018-01-23 11:32:10 | 172.18.4.61
| 84:18:3a:aa:bb:cc | 7c:04:00:11:22:33 | null | NULL |
+-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
[root@PacketFence-6_4_0 logs]#
#
# User connect to WiFi
#
Jan 23 11:31:32 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33]
handling radius autz request: from switch_ip => (172.18.4.61),
connection_type => Wireless-802.11-NoEAP,switch_mac =>
(84:18:3a:aa:bb:cc), mac => [7c:04:00:11:22:33], port => 0, username
=> "7c:04:00:11:22:33", ssid => SSID_A (pf::radius::authorize)
Jan 23 11:31:32 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33] does
not yet exist in database. Adding it now (pf::radius::authorize)
Jan 23 11:31:32 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:31:32 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33] is of
status unreg; belongs into registration VLAN
(pf::role::getRegistrationRole)
Jan 23 11:31:32 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33]
(172.18.4.61) Added VLAN 501 to the returned RADIUS Access-Accept
(pf::Switch::returnRadiusAccessAccept)
#
# User go to captive portal, before authentication
#
Jan 23 11:32:22 httpd.portal(27867) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:32:22 httpd.portal(27867) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:32:22 httpd.portal(27867) INFO: [mac:7c:04:00:11:22:33]
Updating node user_agent with useragent: 'Mozilla/5.0 (iPhone; CPU
iPhone OS....'
(captiveportal::PacketFence::DynamicRouting::Application::process_user_agent)
Jan 23 11:32:25 httpd.portal(26327) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:32:25 httpd.portal(26327) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
#
# User authentication
#
Jan 23 11:33:26 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:33:26 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:33:26 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33]
Authenticating user using sources .....
.
.
.
Jan 23 11:33:26 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33] User
user_ABC has authenticated on the portal. (Class::MOP::Class:::after)
Jan 23 11:33:26 httpd.portal(31161) WARN: [mac:7c:04:00:11:22:33]
Calling match with empty/invalid rule class. Defaulting to
'authentication' (pf::authentication::match)
.
### right after authentication, User stuck in registration vlan
.
Jan 23 11:33:26 httpd.portal(30739) INFO: [mac:7c:04:00:11:22:33] User
user_ABC has authenticated on the portal. (Class::MOP::Class:::after)
Jan 23 11:33:26 httpd.portal(30739) INFO: [mac:7c:04:00:11:22:33] No
provisioner found for 7c:04:00:11:22:33. Continuing.
(captiveportal::PacketFence::DynamicRouting::Module::Provisioning::execute_child)
Jan 23 11:33:26 httpd.portal(30739) INFO: [mac:7c:04:00:11:22:33] User
user_ABC has authenticated on the portal. (Class::MOP::Class:::after)
Jan 23 11:33:26 httpd.portal(30739) INFO: [mac:7c:04:00:11:22:33] User
user_ABC has authenticated on the portal. (Class::MOP::Class:::after)
Jan 23 11:33:26 httpd.portal(30739) INFO: [mac:7c:04:00:11:22:33]
violation 1300003 force-closed for 7c:04:00:11:22:33
(pf::violation::violation_force_close)
Jan 23 11:33:26 httpd.portal(30739) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:33:27 httpd.portal(26327) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:33:27 httpd.portal(26327) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:33:27 httpd.portal(26327) INFO: [mac:7c:04:00:11:22:33]
Releasing device
(captiveportal::PacketFence::DynamicRouting::Module::Root::release)
Jan 23 11:33:27 httpd.portal(26327) INFO: [mac:7c:04:00:11:22:33] User
default has authenticated on the portal. (Class::MOP::Class:::after)
Jan 23 11:33:27 httpd.portal(26327) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:33:27 httpd.portal(26327) INFO: [mac:7c:04:00:11:22:33]
re-evaluating access (manage_register called)
(pf::enforcement::reevaluate_access)
Jan 23 11:33:27 httpd.portal(26327) WARN: [mac:7c:04:00:11:22:33]
Can't re-evaluate access because no open locationlog entry was found
(pf::enforcement::reevaluate_access)
Jan 23 11:34:25 httpd.portal(26927) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:34:25 httpd.portal(26927) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:34:25 httpd.portal(26927) INFO: [mac:7c:04:00:11:22:33] User
default has authenticated on the portal. (Class::MOP::Class:::after)
Jan 23 11:34:25 httpd.portal(26927) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:34:25 httpd.portal(26927) INFO: [mac:7c:04:00:11:22:33]
Reevaluating access of device.
(captiveportal::PacketFence::DynamicRouting::Module::Root::unknown_state)
Jan 23 11:34:25 httpd.portal(26927) INFO: [mac:7c:04:00:11:22:33]
re-evaluating access (manage_register called)
(pf::enforcement::reevaluate_access)
Jan 23 11:34:25 httpd.portal(26927) WARN: [mac:7c:04:00:11:22:33]
Can't re-evaluate access because no open locationlog entry was found
(pf::enforcement::reevaluate_access)
Jan 23 11:34:25 httpd.portal(31158) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:34:25 httpd.portal(31158) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:36:09 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:36:09 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:36:09 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33] User
default has authenticated on the portal. (Class::MOP::Class:::after)
Jan 23 11:36:09 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:36:09 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33]
Reevaluating access of device.
(captiveportal::PacketFence::DynamicRouting::Module::Root::unknown_state)
Jan 23 11:36:09 httpd.portal(31161) INFO: [mac:7c:04:00:11:22:33]
re-evaluating access (manage_register called)
(pf::enforcement::reevaluate_access)
Jan 23 11:36:09 httpd.portal(31161) WARN: [mac:7c:04:00:11:22:33]
Can't re-evaluate access because no open locationlog entry was found
(pf::enforcement::reevaluate_access)
Jan 23 11:36:09 httpd.portal(26927) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:36:09 httpd.portal(26927) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
#
### after few minutes, User is moved to working vlan
#
Jan 23 11:41:09 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33]
handling radius autz request: from switch_ip => (172.18.4.61),
connection_type => Wireless-802.11-NoEAP,switch_mac =>
(84:18:3a:aa:bb:cc), mac => [7c:04:00:11:22:33], port => 0, username
=> "7c:04:00:11:22:33", ssid => SSID_A (pf::radius::authorize)
Jan 23 11:41:09 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33]
Instantiate profile default
(pf::Portal::ProfileFactory::_from_profile)
Jan 23 11:41:09 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33]
Connection type is WIRELESS_MAC_AUTH. Getting role from node_info
(pf::role::getRegisteredRole)
Jan 23 11:41:09 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33]
Username was defined "7c:04:00:11:22:33" - returning role 'role-staff'
(pf::role::getRegisteredRole)
Jan 23 11:41:09 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33] PID:
"user_ABC", Status: reg Returned VLAN: (undefined), Role: role-staff
(pf::role::fetchRoleForNode)
Jan 23 11:41:09 httpd.aaa(15541) INFO: [mac:7c:04:00:11:22:33]
(172.18.4.61) Added VLAN 50 to the returned RADIUS Access-Accept
(pf::Switch::returnRadiusAccessAccept)
Regards,
Tom
On Mon, Jan 22, 2018 at 9:42 PM, Fabrice Durand <[email protected]> wrote:
> Hello Tom,
>
> there : https://pf_mgmt:1443/admin/configuration#configuration/main/advanced
>
> Regards
> Fabrice
>
> Le 2018-01-20 à 19:03, tom lo a écrit :
>> Hi Durand,
>>
>> What change should I make on PF to "disable update locationlog on
>> accounting"?
>>
>>
>> Regards,
>> Tom
>>
>> On Sun, Jan 21, 2018 at 4:31 AM, Durand fabrice <[email protected]> wrote:
>>> Hello Tom,
>>>
>>>
>>> Le 2018-01-20 à 03:02, tom lo a écrit :
>>>> Hi Durand,
>>>>
>>>>
>>>> Thanks for your reply and please see if my understanding is correct
>>>> about the locationlog.
>>>> If the locationlog is correct, from mysql, I should see one entry when
>>>> a device reach captive portal, and another entry immediately after the
>>>> authentication complete, with matching start / end time?
>>>> If the locationlog is wrong, the new entry may be missing even the
>>>> authentication is completed?
>>> In fact when PacketFence receive a radius request , it will update the
>>> location log, so just after the registration on the captive portal
>>> Packetfence need to know where the device is to send a disconnection.
>>> And if the disconnection succeed you will see a new entry in the
>>> locationlog.
>>>>
>>>> I checked a log from an issue reported few hours ago. User
>>>> "12:34:56:33:22:11" completed the authentication at 11:11am, but there
>>>> is no entry about the updated role (staff) for this device until the
>>>> user retry the connection at 13:06. Is this a kind of wrong
>>>> locationlog?
>>> Yes probably if you see no locationlog entry was found in the log.
>>> But it can also be a issue with a cache on the controller,if there is no new
>>> radius request each time the device connect on the ssid per example.
>>>>
>>>> I also found another mysql output for a device which had a smooth VLAN
>>>> re-direction in its 1st try. mysql output shows one entry when a
>>>> device reach captive portal, and another entry after the
>>>> authentication complete with matching start / end time.
>>>>
>>>> Also, for your information, we are using Ruckus ZoneDirector and the
>>>> SSID setting is mac-auth.
>>>>
>>>> I'll check with users in real-time to see about the queue and mysql
>>>> output, and let you know the result.
>>>>
>>>>
>>>> The following is the related log / mysql output for the issue reported.
>>> Before "Jan 20 11:11:59" do you see "INFO: [mac:12:34:56:33:22:11] handling
>>> radius autz request" ? if no then the device is on the registration network
>>> but PacketFence never receive the radius request !
>>>>
>>>> Jan 20 11:11:59 httpd.portal(6296) INFO: [mac:12:34:56:33:22:11]
>>>> re-evaluating access (manage_register called)
>>>> (pf::enforcement::reevaluate_access)
>>>> Jan 20 11:11:59 httpd.portal(6296) WARN: [mac:12:34:56:33:22:11] Can't
>>>> re-evaluate access because no open locationlog entry was found
>>>> (pf::enforcement::reevaluate_access)
>>>> Jan 20 11:15:29 httpd.aaa(2033) INFO: [mac:12:34:56:33:22:11] Updating
>>>> locationlog from accounting request
>>>> (pf::api::handle_accounting_metadata)
>>>> Jan 20 13:06:53 httpd.aaa(2033) INFO: [mac:12:34:56:33:22:11] handling
>>>> radius autz request.......
>>>>
>>>> select * from locationlog where mac="12:34:56:33:22:11";
>>>>
>>>> +-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
>>>> | mac | switch | port | vlan | role
>>>> |connection_type | connection_sub_type | dot1x_username | ssid
>>>> | start_time | end_time | switch_ip |switch_mac
>>>> | stripped_user_name | realm | session_id |
>>>>
>>>> +-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
>>>> | 12:34:56:33:22:11 | 172.18.4.61 | 0 | 50 | staff
>>>> |Wireless-802.11-NoEAP | NULL | 12:34:56:33:22:11 |SSID_A
>>>> | 2018-01-20 13:06:53 | 0000-00-00 00:00:00 | 172.18.4.61|
>>>> 11:22:33:44:55:0d
>>>> | 12:34:56:33:22:11 | null | NULL |
>>>> | 12:34:56:33:22:11 | 172.18.4.61 | 0 | 501 | registration
>>>> |Wireless-802.11-NoEAP | NULL | 12:34:56:33:22:11 |SSID_A
>>>> | 2018-01-20 11:10:51 | 2018-01-20 11:11:12 | 172.18.4.61|
>>>> 11:22:33:44:55:09
>>>> | 12:34:56:33:22:11 | null | NULL |
>>>> | 12:34:56:33:22:11 | 172.18.4.61 | 0 | 501 | registration
>>>> |Wireless-802.11-NoEAP | NULL | 12:34:56:33:22:11 |SSID_A
>>>> | 2018-01-20 11:11:12 | 2018-01-20 11:11:38 | 172.18.4.61|
>>>> 11:22:33:44:55:0d
>>>> | 12:34:56:33:22:11 | null | NULL |
>>>>
>>>> +-------------------+-------------+------+------+--------------+-----------------------+---------------------+-------------------+--------------+---------------------+---------------------+-------------+-------------------+--------------------+-------+------------+
>>> Really strange , it look that something closed the locationlog just before
>>> you register on the portal.
>>> Can you disable update locationlog on accounting and retry ?
>>> Regards
>>> Fabrice
>>>
>>>
>>>> Regards,
>>>> Tom
>>>>
>>>>
>>>> On Sat, Jan 20, 2018 at 10:01 AM, Durand fabrice via PacketFence-users
>>>> <[email protected]> wrote:
>>>>> Hello Tom,
>>>>>
>>>>> just after a radius request, can you check in the database if the
>>>>> locationlog is correct ? (the radius request is suppose to update the
>>>>> locationlog)
>>>>>
>>>>> And also when it failed.
>>>>>
>>>>> select * from locationlog where mac="ab:cd:ef:12:34:56";
>>>>>
>>>>> Last thing, can you verify if the queue is full when this problem occur
>>>>> (from the admin gui in queue)
>>>>>
>>>>> Regards
>>>>> Fabrice
>>>>>
>>>>>
>>>>> Le 2018-01-16 à 20:33, tom lo via PacketFence-users a écrit :
>>>>>> Hi,
>>>>>>
>>>>>>
>>>>>> We checked packetfence.log and did a comparison between working and
>>>>>> non-working VLAN redirection.
>>>>>>
>>>>>> When VLAN redirection works properly, "re-evaluating access" related
>>>>>> log has no warning.
>>>>>>
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> re-evaluating access (manage_register called)
>>>>>> (pf::enforcement::reevaluate_access)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56] is
>>>>>> currentlog connected at (172.18.4.62) ifIndex 0 registration
>>>>>> (pf::enforcement::_should_we_reassign_vlan)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Connection type is WIRELESS_MAC_AUTH. Getting role from node_info
>>>>>> (pf::role::getRegisteredRole)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Username was defined "ab:cd:ef:12:34:56" - returning role 'edu-intern'
>>>>>> (pf::role::getRegisteredRole)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56] PID:
>>>>>> "user001", Status: reg Returned VLAN: (undefined), Role: edu-intern
>>>>>> (pf::role::fetchRoleForNode)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56] VLAN
>>>>>> reassignment required (current VLAN = 501 but should be in VLAN 50)
>>>>>> (pf::enforcement::_should_we_reassign_vlan)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> switch port is (172.18.4.62) ifIndex unknown connection type: WiFi MAC
>>>>>> Auth (pf::enforcement::_vlan_reevaluation)
>>>>>>
>>>>>>
>>>>>> But if VLAN redirection fail, we found warning "Can't re-evaluate
>>>>>> access because no open locationlog entry was found".
>>>>>>
>>>>>> Jan 12 14:28:20 httpd.portal(2273) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> re-evaluating access (manage_register called)
>>>>>> (pf::enforcement::reevaluate_access)
>>>>>> Jan 12 14:28:20 httpd.portal(2273) WARN: [mac:ab:cd:ef:12:34:56] Can't
>>>>>> re-evaluate access because no open locationlog entry was found
>>>>>> (pf::enforcement::reevaluate_access)
>>>>>>
>>>>>>
>>>>>>
>>>>>> The full log of both success and failed VLAN redirection are as below.
>>>>>>
>>>>>> #### 1st try, authentication success and being moved to production VLAN
>>>>>> (50)
>>>>>>
>>>>>> Jan 12 12:06:48 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56] handling
>>>>>> radius autz request: from switch_ip => (172.18.4.62), connection_type
>>>>>> => Wireless-802.11-NoEAP,switch_mac => (84:18:3a:12:34:56), mac =>
>>>>>> [ab:cd:ef:12:34:56], port => 0, username => "ab:cd:ef:12:34:56", ssid
>>>>>> => SSID_A (pf::radius::authorize)
>>>>>> Jan 12 12:06:48 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:06:48 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56] is of
>>>>>> status unreg; belongs into registration VLAN
>>>>>> (pf::role::getRegistrationRole)
>>>>>> Jan 12 12:06:48 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> (172.18.4.62) Added VLAN 501 to the returned RADIUS Access-Accept
>>>>>> (pf::Switch::returnRadiusAccessAccept)
>>>>>>
>>>>>> Jan 12 12:07:05 httpd.portal(3099) INFO: [mac:unknown] Instantiate
>>>>>> profile default (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:05 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:05 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:05 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Updating node user_agent with useragent: 'Mozilla/5.0 (Macintosh;
>>>>>> Intel Mac OS X 10_11_6) AppleWebKit/601.7.8 (KHTML, like Gecko)'
>>>>>>
>>>>>>
>>>>>> (captiveportal::PacketFence::DynamicRouting::Application::process_user_agent)
>>>>>> Jan 12 12:07:05 httpd.portal(3102) INFO: [mac:unknown] Instantiate
>>>>>> profile default (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:05 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:05 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>>
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Authenticating user using sources : edu_intern_AD,edu_Staff_AD
>>>>>>
>>>>>>
>>>>>> (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Login::authenticate)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> [edu_intern_AD] Authentication successful for user001
>>>>>> (pf::Authentication::Source::LDAPSource::authenticate)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Authentication successful for 'user001' in source edu_intern_AD (AD)
>>>>>> (pf::authentication::authenticate)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Successfully authenticated user001
>>>>>>
>>>>>>
>>>>>> (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Login::authenticate)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) WARN: [mac:ab:cd:ef:12:34:56]
>>>>>> Calling match with empty/invalid rule class. Defaulting to
>>>>>> 'authentication' (pf::authentication::match)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] Using
>>>>>> sources edu_intern_AD for matching (pf::authentication::match)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Matched rule (rule1) in source edu_intern_AD, returning actions.
>>>>>> (pf::Authentication::Source::match)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) WARN: [mac:ab:cd:ef:12:34:56]
>>>>>> Calling match with empty/invalid rule class. Defaulting to
>>>>>> 'authentication' (pf::authentication::match)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] Using
>>>>>> sources edu_intern_AD for matching (pf::authentication::match)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Matched rule (rule1) in source edu_intern_AD, returning actions.
>>>>>> (pf::Authentication::Source::match)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 12:07:18 httpd.portal(3099) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 12:07:18 httpd.portal(3101) INFO: [mac:unknown] Instantiate
>>>>>> profile default (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3101) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3101) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3101) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 12:07:18 httpd.portal(3101) INFO: [mac:ab:cd:ef:12:34:56] No
>>>>>> provisioner found for ab:cd:ef:12:34:56. Continuing.
>>>>>>
>>>>>>
>>>>>> (captiveportal::PacketFence::DynamicRouting::Module::Provisioning::execute_child)
>>>>>> Jan 12 12:07:18 httpd.portal(3101) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 12:07:18 httpd.portal(3101) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 12:07:18 httpd.portal(3101) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> violation 1300003 force-closed for ab:cd:ef:12:34:56
>>>>>> (pf::violation::violation_force_close)
>>>>>> Jan 12 12:07:18 httpd.portal(3101) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:unknown] Instantiate
>>>>>> profile default (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Releasing device
>>>>>> (captiveportal::PacketFence::DynamicRouting::Module::Root::release)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> default has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) WARN: [mac:ab:cd:ef:12:34:56] Use
>>>>>> of uninitialized value in string eq at
>>>>>> /usr/local/pf/lib/pf/Switch/Ruckus.pm line 75.
>>>>>> (pf::Switch::Ruckus::supportsWebFormRegistration)
>>>>>>
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> re-evaluating access (manage_register called)
>>>>>> (pf::enforcement::reevaluate_access)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56] is
>>>>>> currentlog connected at (172.18.4.62) ifIndex 0 registration
>>>>>> (pf::enforcement::_should_we_reassign_vlan)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Connection type is WIRELESS_MAC_AUTH. Getting role from node_info
>>>>>> (pf::role::getRegisteredRole)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Username was defined "ab:cd:ef:12:34:56" - returning role 'edu-intern'
>>>>>> (pf::role::getRegisteredRole)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56] PID:
>>>>>> "user001", Status: reg Returned VLAN: (undefined), Role: edu-intern
>>>>>> (pf::role::fetchRoleForNode)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56] VLAN
>>>>>> reassignment required (current VLAN = 501 but should be in VLAN 50)
>>>>>> (pf::enforcement::_should_we_reassign_vlan)
>>>>>> Jan 12 12:07:18 httpd.portal(3102) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> switch port is (172.18.4.62) ifIndex unknown connection type: WiFi MAC
>>>>>> Auth (pf::enforcement::_vlan_reevaluation)
>>>>>>
>>>>>> Jan 12 12:07:27 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56] handling
>>>>>> radius autz request: from switch_ip => (172.18.4.62), connection_type
>>>>>> => Wireless-802.11-NoEAP,switch_mac => (84:18:3a:12:34:56), mac =>
>>>>>> [ab:cd:ef:12:34:56], port => 0, username => "ab:cd:ef:12:34:56", ssid
>>>>>> => SSID_A (pf::radius::authorize)
>>>>>> Jan 12 12:07:27 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 12:07:27 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Connection type is WIRELESS_MAC_AUTH. Getting role from node_info
>>>>>> (pf::role::getRegisteredRole)
>>>>>> Jan 12 12:07:27 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56] Username
>>>>>> was defined "ab:cd:ef:12:34:56" - returning role 'edu-intern'
>>>>>> (pf::role::getRegisteredRole)
>>>>>> Jan 12 12:07:27 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56] PID:
>>>>>> "user001", Status: reg Returned VLAN: (undefined), Role: edu-intern
>>>>>> (pf::role::fetchRoleForNode)
>>>>>> Jan 12 12:07:27 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> (172.18.4.62) Added VLAN 50 to the returned RADIUS Access-Accept
>>>>>> (pf::Switch::returnRadiusAccessAccept)
>>>>>>
>>>>>>
>>>>>> #### 2nd try, first de-register the mac address in PF GUI, then
>>>>>> perform authentication again, and the device stays in registration
>>>>>> VLAN (501)
>>>>>>
>>>>>>
>>>>>> Jan 12 14:26:00 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56] handling
>>>>>> radius autz request: from switch_ip => (172.18.4.62), connection_type
>>>>>> => Wireless-802.11-NoEAP,switch_mac => (24:79:2a:12:34:56), mac =>
>>>>>> [ab:cd:ef:12:34:56], port => 0, username => "ab:cd:ef:12:34:56", ssid
>>>>>> => SSID_A (pf::radius::authorize)
>>>>>> Jan 12 14:26:00 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:26:01 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56] is of
>>>>>> status unreg; belongs into registration VLAN
>>>>>> (pf::role::getRegistrationRole)
>>>>>> Jan 12 14:26:01 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> (172.18.4.62) Added VLAN 501 to the returned RADIUS Access-Accept
>>>>>> (pf::Switch::returnRadiusAccessAccept)
>>>>>>
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Authenticating user using sources : edu_intern_AD,edu_Staff_AD
>>>>>>
>>>>>>
>>>>>> (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Login::authenticate)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) ERROR: [mac:ab:cd:ef:12:34:56]
>>>>>> Error binding 'Connection reset by peer' (pf::LDAP::bind)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) WARN: [mac:ab:cd:ef:12:34:56] LDAP
>>>>>> connection expired (pf::LDAP::expire_if)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> [edu_intern_AD] Authentication successful for user001
>>>>>> (pf::Authentication::Source::LDAPSource::authenticate)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Authentication successful for 'user001' in source edu_intern_AD (AD)
>>>>>> (pf::authentication::authenticate)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Successfully authenticated user001
>>>>>>
>>>>>>
>>>>>> (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Login::authenticate)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) WARN: [mac:ab:cd:ef:12:34:56]
>>>>>> Calling match with empty/invalid rule class. Defaulting to
>>>>>> 'authentication' (pf::authentication::match)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] Using
>>>>>> sources edu_intern_AD for matching (pf::authentication::match)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Matched rule (rule1) in source edu_intern_AD, returning actions.
>>>>>> (pf::Authentication::Source::match)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) WARN: [mac:ab:cd:ef:12:34:56]
>>>>>> Calling match with empty/invalid rule class. Defaulting to
>>>>>> 'authentication' (pf::authentication::match)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] Using
>>>>>> sources edu_intern_AD for matching (pf::authentication::match)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Matched rule (rule1) in source edu_intern_AD, returning actions.
>>>>>> (pf::Authentication::Source::match)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 14:28:20 httpd.portal(2282) INFO: [mac:ab:cd:ef:12:34:56] Found
>>>>>> source edu_intern_AD in session. (Class::MOP::Class:::around)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:unknown] Memory
>>>>>> configuration is not valid anymore for key
>>>>>> interfaces::management_network in local cached_hash
>>>>>> (pfconfig::cached::is_valid)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:unknown] Instantiate
>>>>>> profile default (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56] No
>>>>>> provisioner found for ab:cd:ef:12:34:56. Continuing.
>>>>>>
>>>>>>
>>>>>> (captiveportal::PacketFence::DynamicRouting::Module::Provisioning::execute_child)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> user001 has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> violation 1300003 force-closed for ab:cd:ef:12:34:56
>>>>>> (pf::violation::violation_force_close)
>>>>>> Jan 12 14:28:20 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:28:20 httpd.portal(2273) INFO: [mac:unknown] Memory
>>>>>> configuration is not valid anymore for key
>>>>>> interfaces::management_network in local cached_hash
>>>>>> (pfconfig::cached::is_valid)
>>>>>> Jan 12 14:28:20 httpd.portal(2273) INFO: [mac:unknown] Instantiate
>>>>>> profile default (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:28:20 httpd.portal(2273) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:28:20 httpd.portal(2273) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:28:20 httpd.portal(2273) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Releasing device
>>>>>> (captiveportal::PacketFence::DynamicRouting::Module::Root::release)
>>>>>> Jan 12 14:28:20 httpd.portal(2273) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> default has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 14:28:20 httpd.portal(2273) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>>
>>>>>> Jan 12 14:28:20 httpd.portal(2273) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> re-evaluating access (manage_register called)
>>>>>> (pf::enforcement::reevaluate_access)
>>>>>> Jan 12 14:28:20 httpd.portal(2273) WARN: [mac:ab:cd:ef:12:34:56] Can't
>>>>>> re-evaluate access because no open locationlog entry was found
>>>>>> (pf::enforcement::reevaluate_access)
>>>>>>
>>>>>> Jan 12 14:29:20 httpd.aaa(8040) INFO: [mac:ab:cd:ef:12:34:56] Updating
>>>>>> locationlog from accounting request
>>>>>> (pf::api::handle_accounting_metadata)
>>>>>> Jan 12 14:29:23 httpd.portal(2256) INFO: [mac:unknown] Instantiate
>>>>>> profile default (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:29:23 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:29:23 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:29:23 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56] User
>>>>>> default has authenticated on the portal. (Class::MOP::Class:::after)
>>>>>> Jan 12 14:29:23 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:29:23 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Reevaluating access of device.
>>>>>>
>>>>>> (captiveportal::PacketFence::DynamicRouting::Module::Root::unknown_state)
>>>>>>
>>>>>> Jan 12 14:29:23 httpd.portal(2256) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> re-evaluating access (manage_register called)
>>>>>> (pf::enforcement::reevaluate_access)
>>>>>> Jan 12 14:29:23 httpd.portal(2256) WARN: [mac:ab:cd:ef:12:34:56] Can't
>>>>>> re-evaluate access because no open locationlog entry was found
>>>>>> (pf::enforcement::reevaluate_access)
>>>>>> Jan 12 14:29:23 httpd.portal(3156) INFO: [mac:unknown] Memory
>>>>>> configuration is not valid anymore for key
>>>>>> interfaces::management_network in local cached_hash
>>>>>> (pfconfig::cached::is_valid)
>>>>>> Jan 12 14:29:23 httpd.portal(3156) INFO: [mac:unknown] Instantiate
>>>>>> profile default (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:29:23 httpd.portal(3156) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>> Jan 12 14:29:23 httpd.portal(3156) INFO: [mac:ab:cd:ef:12:34:56]
>>>>>> Instantiate profile default
>>>>>> (pf::Portal::ProfileFactory::_from_profile)
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> Regards,
>>>>>> Tom
>>>>>>
>>>>>>
>>>>>> On Tue, Jan 16, 2018 at 10:57 PM, tom lo <[email protected]>
>>>>>> wrote:
>>>>>>> Hi Ludovic,
>>>>>>>
>>>>>>> We are still using ZoneDirector, not the newer SmartZone controller,
>>>>>>> and seems Packetfence start supporting SmartZone from version 6.5
>>>>>>> In version 6.4, which we are using, there are only one switch type for
>>>>>>> select "Ruckus Wireless Controllers".
>>>>>>> So you would suggest we to try another switch module?
>>>>>>>
>>>>>>>
>>>>>>> Regards,
>>>>>>> Tom
>>>>>>>
>>>>>>>
>>>>>>> On Tue, Jan 16, 2018 at 10:48 PM, Ludovic Zammit <[email protected]>
>>>>>>> wrote:
>>>>>>>> Hello there,
>>>>>>>>
>>>>>>>> PacketFence two different switch module, there is a legacy one and the
>>>>>>>> other
>>>>>>>> one is meant for the SmartZone controller.
>>>>>>>>
>>>>>>>> Have you tried to change the switch module ?
>>>>>>>>
>>>>>>>> Thanks,
>>>>>>>>
>>>>>>>>
>>>>>>>> Ludovic Zammit
>>>>>>>> [email protected] :: +1.514.447.4918 (x145) :: www.inverse.ca
>>>>>>>> Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and
>>>>>>>> PacketFence
>>>>>>>> (http://packetfence.org)
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> On Jan 16, 2018, at 9:32 AM, tom lo via PacketFence-users
>>>>>>>> <[email protected]> wrote:
>>>>>>>>
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>>
>>>>>>>> We've been using Packetfence ZEN 6.4 with Ruckus ZoneDirector for a
>>>>>>>> while, to authentication user against AD before putting them into
>>>>>>>> production VLAN.
>>>>>>>> It was working fine until recently that users report that when they
>>>>>>>> doing authentication in captive portal, they start seeing the message
>>>>>>>> "Unable to detect network connectivity. Try to restarting your web
>>>>>>>> browser or opening a new tab to see if your access has been
>>>>>>>> successfully enabled."
>>>>>>>> They tried to turn off/on WiFi and they will see "Your network should
>>>>>>>> be enabled within a minute or two. If it is not reboot your computer",
>>>>>>>> if they wait for around 15 mins, sometimes they found their device
>>>>>>>> could fall into production VLAN.
>>>>>>>> During the issue happens to user, we could see in ZoneDirector that
>>>>>>>> the client device were still in registration VLN,
>>>>>>>> and from packetfence admin portal, user mac address "Info" page, the
>>>>>>>> role is set to a registered role.
>>>>>>>> If we delete the client connection manually from ZoneDirector GUI, we
>>>>>>>> found the client device will re-connect and fall into the production
>>>>>>>> VLAN.
>>>>>>>>
>>>>>>>> We tried one suggestion from this mailing list, toggle $TRUE and
>>>>>>>> $FALSE for synchronize_locationlog in /Switch/Ruckus.pm#L190, and
>>>>>>>> restart httpd.portal, but made no difference.
>>>>>>>>
>>>>>>>> We captured the packetfence.log, and found some warning but not sure
>>>>>>>> if it's related to the issue.
>>>>>>>> httpd.portal(2282) WARN: [mac:ab:cd:00:00:12:34] Use of uninitialized
>>>>>>>> value in concatenation (.) or string at
>>>>>>>> /usr/local/pf/lib/pf/authentication.pm line 284.
>>>>>>>> httpd.portal(2282) WARN: [mac:ab:cd:00:00:12:34] Calling match with
>>>>>>>> empty/invalid rule class. Defaulting to 'authentication'
>>>>>>>> (pf::authentication::match)
>>>>>>>> httpd.portal(2245) WARN: [mac:ab:cd:00:00:12:34] Can't re-evaluate
>>>>>>>> access because no open locationlog entry was found
>>>>>>>> (pf::enforcement::reevaluate_access)
>>>>>>>>
>>>>>>>> Please advise what we could do to troubleshoot the issue. Thanks for
>>>>>>>> your
>>>>>>>> time.
>>>>>>>>
>>>>>>>>
>>>>>>>> Regards,
>>>>>>>> Tom
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> ------------------------------------------------------------------------------
>>>>>>>> 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
>>>>>>>>
>>>>>>>>
>>>>>> ------------------------------------------------------------------------------
>>>>>> 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
>>>>>
>>>>>
>>>>>
>>>>> ------------------------------------------------------------------------------
>>>>> 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
>>>
>
> --
> Fabrice Durand
> [email protected] :: +1.514.447.4918 (x135) :: www.inverse.ca
> Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence
> (http://packetfence.org)
>
------------------------------------------------------------------------------
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
