Hi Fabrice,

Just to see if you have any idea or suggestions for us to troubleshoot
the issues.



Regards,
Tom

On Thu, Jan 25, 2018 at 12:21 PM, tom lo <tom.16413515...@gmail.com> wrote:
> Hi Fabrice,
>
> Here is the content from the log file httpd.portal.access when the
> user hit the portal.
>
>
> 172.18.x.y - - [23/Jan/2018:11:31:37]  "captive.apple.com" "GET
> /hotspot-detect.html HTTP/1.0" 302 1080 "-"
> "CaptiveNetworkSupport-355.30.1 wispr" 4896
> 172.18.x.y - - [23/Jan/2018:11:32:22]  "www.apple.com" "GET /
> HTTP/1.1" 302 1101 "-" "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like
> Mac OS X) AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 5069
> 172.18.x.y - - [23/Jan/2018:11:32:22]  "byod.a_domain.com" "GET
> /captive-portal?destination_url=http://www.apple.com/&; HTTP/1.1" 200
> 31211 "-" "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 2823405
> 172.18.x.y - - [23/Jan/2018:11:32:25]  "byod.a_domain.com" "GET
> /common/styles.css HTTP/1.1" 200 22524
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 8248
> 172.18.x.y - - [23/Jan/2018:11:32:25]  "byod.a_domain.com" "GET
> /content/captiveportal.js HTTP/1.1" 200 2771
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 2990
> 172.18.x.y - - [23/Jan/2018:11:32:25]  "byod.a_domain.com" "GET
> /common/pf.js HTTP/1.1" 200 4259
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 4216
> 172.18.x.y - - [23/Jan/2018:11:32:25]  "byod.a_domain.com" "GET
> /common/A_Logo_Black_trans_med.png HTTP/1.1" 200 6418
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 3465
> 172.18.x.y - - [23/Jan/2018:11:32:25]  "byod.a_domain.com" "GET
> /common/jquery-1.11.3.min.js HTTP/1.1" 200 95957
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 19690
> 172.18.x.y - - [23/Jan/2018:11:32:25]  "byod.a_domain.com" "GET
> /common/img/sprite.svg HTTP/1.1" 200 27622
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 6047
> 172.18.x.y - - [23/Jan/2018:11:32:25]  "byod.a_domain.com" "POST
> /record_destination_url HTTP/1.1" 200 -
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 35716
> 172.18.x.y - - [23/Jan/2018:11:32:25]  "www.apple.com" "GET
> /library/test/success.html HTTP/1.0" 302 1080 "-"
> "CaptiveNetworkSupport-355.30.1 wispr" 4852
> 172.18.x.y - - [23/Jan/2018:11:33:26]  "www.apple.com" "GET
> /library/test/success.html HTTP/1.0" 302 1080 "-"
> "CaptiveNetworkSupport-355.30.1 wispr" 4972
> 172.18.x.y - - [23/Jan/2018:11:33:26]  "byod.a_domain.com" "POST
> /signup HTTP/1.1" 302 294
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 210063
> 172.18.x.y - - [23/Jan/2018:11:33:26]  "byod.a_domain.com" "GET
> /captive-portal HTTP/1.1" 302 286
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 52410
> 172.18.x.y - - [23/Jan/2018:11:33:27]  "byod.a_domain.com" "GET
> /access HTTP/1.1" 200 6351
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 51125
> 172.18.x.y - - [23/Jan/2018:11:33:27]  "byod.a_domain.com" "GET
> /content/timerbar.js HTTP/1.1" 200 4089
> "https://byod.a_domain.com/access"; "Mozilla/5.0 (iPhone; CPU iPhone OS
> 11_2_2 like Mac OS X) AppleWebKit/604.4.7 (KHTML, like Gecko)
> Mobile/15C202" 2634
> 172.18.x.y - - [23/Jan/2018:11:33:27]  "www.apple.com" "GET
> /library/test/success.html HTTP/1.0" 302 1080 "-"
> "CaptiveNetworkSupport-355.30.1 wispr" 4374
> 172.18.x.y - - [23/Jan/2018:11:34:25]  "www.apple.com" "GET
> /library/test/success.html HTTP/1.0" 302 1080 "-"
> "CaptiveNetworkSupport-355.30.1 wispr" 3925
> 172.18.x.y - - [23/Jan/2018:11:34:25]  "byod.a_domain.com" "GET
> /captive-portal?destination_url=http://www.apple.com/&; HTTP/1.1" 200
> 3770 "-" "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 48716
> 172.18.x.y - - [23/Jan/2018:11:34:25]  "byod.a_domain.com" "POST
> /record_destination_url HTTP/1.1" 200 -
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 31153
> 172.18.x.y - - [23/Jan/2018:11:34:25]  "www.apple.com" "GET
> /library/test/success.html HTTP/1.0" 302 1080 "-"
> "CaptiveNetworkSupport-355.30.1 wispr" 4074
> 172.18.x.y - - [23/Jan/2018:11:35:24]  "captive.apple.com" "GET
> /hotspot-detect.html HTTP/1.0" 302 1080 "-"
> "CaptiveNetworkSupport-355.30.1 wispr" 5828
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "www.apple.com" "GET /
> HTTP/1.1" 302 1101 "-" "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like
> Mac OS X) AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 4398
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "byod.a_domain.com" "GET
> /captive-portal?destination_url=http://www.apple.com/&; HTTP/1.1" 200
> 3770 "-" "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 53958
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "byod.a_domain.com" "GET
> /common/pf.js HTTP/1.1" 200 4259
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 2187
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "byod.a_domain.com" "GET
> /content/captiveportal.js HTTP/1.1" 200 2771
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 2038
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "byod.a_domain.com" "GET
> /common/styles.css HTTP/1.1" 200 22524
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 6977
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "byod.a_domain.com" "GET
> /common/A_Logo_Black_trans_med.png HTTP/1.1" 200 6418
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 2408
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "byod.a_domain.com" "GET
> /common/jquery-1.11.3.min.js HTTP/1.1" 200 95957
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 24597
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "byod.a_domain.com" "GET
> /common/img/sprite.svg HTTP/1.1" 200 27622
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 5308
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "byod.a_domain.com" "POST
> /record_destination_url HTTP/1.1" 200 -
> "https://byod.a_domain.com/captive-portal?destination_url=http://www.apple.com/&";
> "Mozilla/5.0 (iPhone; CPU iPhone OS 11_2_2 like Mac OS X)
> AppleWebKit/604.4.7 (KHTML, like Gecko) Mobile/15C202" 27006
> 172.18.x.y - - [23/Jan/2018:11:36:09]  "www.apple.com" "GET
> /library/test/success.html HTTP/1.0" 302 1080 "-"
> "CaptiveNetworkSupport-355.30.1 wispr" 3945
>
>
>
> Regards,
> Tom
>
> On Thu, Jan 25, 2018 at 10:27 AM, Durand fabrice <fdur...@inverse.ca> wrote:
>>
>>
>> Le 2018-01-23 à 04:41, tom lo a écrit :
>>>
>>> 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?)
>>
>> yes ... do you have the content of the httpd.portal.access when the user hit
>> the portal ?
>>
>>>
>>> 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 <fdur...@inverse.ca>
>>> 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 <fdur...@inverse.ca>
>>>>> 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
>>>>>>> <packetfence-users@lists.sourceforge.net> 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 <tom.16413515...@gmail.com>
>>>>>>>>> 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
>>>>>>>>>> <lzam...@inverse.ca>
>>>>>>>>>> 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
>>>>>>>>>>> lzam...@inverse.ca ::  +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
>>>>>>>>>>> <packetfence-users@lists.sourceforge.net> 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
>>>>>>>>>>> PacketFence-users@lists.sourceforge.net
>>>>>>>>>>> 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
>>>>>>>>> PacketFence-users@lists.sourceforge.net
>>>>>>>>> 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
>>>>>>>> PacketFence-users@lists.sourceforge.net
>>>>>>>> https://lists.sourceforge.net/lists/listinfo/packetfence-users
>>>>
>>>> --
>>>> Fabrice Durand
>>>> fdur...@inverse.ca ::  +1.514.447.4918 (x135) ::  www.inverse.ca
>>>> Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence
>>>> (http://packetfence.org)
>>>>
>>

------------------------------------------------------------------------------
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
PacketFence-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/packetfence-users

Reply via email to