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