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