Here is the portal debug log for the our Aruba IAP's. first log is redirect URL set to https://PACKETFENCESERVER/. Second is set to https://PACKETFENCESERVER/Aruba::Instant_Access
NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:45:37 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:45:37 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:46:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:46:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:46:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:46:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:46:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:46:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:46:37 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:46:37 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:46:37 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:46:37 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:46:37 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:46:37 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:47:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:47:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:47:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:47:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:47:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:47:07 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:unknown] Adding session parameter from dispatcher session to Catalyst session : _client_mac : 30:24:32:a3:ef:ad (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:unknown] Matched IP '10.10.10.145' to MAC address '30:24:32:a3:ef:ad' using SQL 'ip4log' table (pf::ip4log::ip2mac) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='httpd.portal', key='session:302432a3efad', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::Portal::Session object (pf::Portal::Session::new) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] using session id 'b21929f60cb26fe36e48926c33f1903c' (pf::Portal::Session::_initialize) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='httpd.portal', key='b21929f60cb26fe36e48926c33f1903c', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Authorized locale(s) are en_US (pf::Portal::Session::getLanguages) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] locale from the browser is en_US (pf::Portal::Session::getLanguages) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Setting locale to en_US (pf::Portal::Session::_initializeI18n) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _client_ip : 192.168.20.97 (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _destination_url : http://www.packetfence.org/ (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _grant_url : undef (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _client_mac : 30:24:32:a3:ef:ad (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _profile : pf::Connection::Profile=HASH(0x55c560067858) (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='httpd.portal', key='b21929f60cb26fe36e48926c33f1903c', size=1577, expires='6h', cache='Redis', time='0ms' (CHI::Driver::_log_set_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Remote Address is 10.10.10.145. Client is behind proxy? Returning: 10.10.10.145 according to HTTP Headers (captiveportal::PacketFence::Model::Portal::Session::_build_clientIP) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Trying to match MAC address to IP '10.10.10.145' using SQL 'ip4log' table (pf::ip4log::ip2mac) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Viewing an 'ip4log' table entry for the following IP address '10.10.10.145' (pf::ip4log::_view_by_ip) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Matched IP '10.10.10.145' to MAC address '30:24:32:a3:ef:ad' using SQL 'ip4log' table (pf::ip4log::ip2mac) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) INFO: [mac:30:24:32:a3:ef:ad] Instantiate profile default (pf::Connection::ProfileFactory::_from_profile) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::Connection::Profile object (pf::Connection::Profile::new) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Authorized locale(s) are en_US (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] locale from the browser is en_US (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] locale from the browser en is not supported (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Language locale from the browser en_US is not supported (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Language locale from the browser en is not supported (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] prefered user languages are en_US (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Setting locale to en_US (captiveportal::PacketFence::Controller::Root::setupLanguage) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='httpd.portal', key='user_session:f32837e39b8e178015b16fd38d7e5692ab2122b8', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_blackhole_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Building Authentication Choice module using sources : (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Choice::BUILD) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_oauth_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Building Authentication Choice module using sources : (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Choice::BUILD) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_guest_policy is using sources : null (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Building Authentication Choice module using sources : null (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Choice::BUILD) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_login_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_billing_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_saml_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Building Authentication Choice module using sources : (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Choice::BUILD) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Destination is : https://nac1.bluedogrv.lan/?cmd (captiveportal::PacketFence::DynamicRouting::Application::process_destination_url) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='fingerbank::Config::read_config', cache='Redis', time='1ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='fingerbank::Config::read_config-cached_at', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='fingerbank::Config::read_config', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='fingerbank::Config::read_config-cached_at', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:36 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='pf::fingerbank::endpoint_attributes::request::30:24:32:a3:ef:ad', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': MISS (not in cache) (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='Default', key='{"server":" 127.0.0.1:6380"}', size=1, expires='never', cache='RawMemory', time='0ms' (CHI::Driver::_log_set_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] checking handle (pf::db::is_old_connection_good) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] we are currently connected (pf::db::is_old_connection_good) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] not checking db handle, it has been less than 30 sec from last connection (pf::db::is_old_connection_good) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] No wsrep provider so considering wsrep as healthy (pf::db::db_wsrep_healthy) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Setting current module id : default_policy (captiveportal::PacketFence::DynamicRouting::Application::current_module_id) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /captive-portal matches /status/billing (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /captive-portal matches /billing.* (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /captive-portal matches /logout (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /captive-portal matches /access (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /captive-portal matches /record_destination_url (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Executing current module from session default_policy+default_registration_policy (captiveportal::PacketFence::DynamicRouting::ModuleManager::execute_child) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Setting current module id : default_policy+default_registration_policy (captiveportal::PacketFence::DynamicRouting::Application::current_module_id) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Executing current module from session default_policy+default_registration_policy+default_login_policy (captiveportal::PacketFence::DynamicRouting::ModuleManager::execute_child) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Setting current module id : default_policy+default_registration_policy+default_login_policy (captiveportal::PacketFence::DynamicRouting::Application::current_module_id) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Previous : default_policy, Current module : default_policy+default_registration_policy+default_login_policy (captiveportal::PacketFence::DynamicRouting::Application::_render) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Previous : default_policy, Current module : default_policy+default_registration_policy+default_login_policy (captiveportal::PacketFence::DynamicRouting::Application::_render) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Rendering content-with-choice.html (captiveportal::PacketFence::DynamicRouting::Application::render) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Previous : default_policy, Current module : default_policy+default_registration_policy+default_login_policy (captiveportal::PacketFence::DynamicRouting::Application::_render) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Previous : default_policy, Current module : default_policy+default_registration_policy+default_login_policy (captiveportal::PacketFence::DynamicRouting::Application::_render) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] Setting previous module id : default_policy+default_registration_policy+default_login_policy (captiveportal::PacketFence::DynamicRouting::Application::previous_module_id) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='httpd.portal', key='user_session:f32837e39b8e178015b16fd38d7e5692ab2122b8', size=30, expires='6h', cache='Redis', time='1ms' (CHI::Driver::_log_set_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='httpd.portal', key='expires:302432a3efad', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='httpd.portal', key='expires:302432a3efad', size=24, expires='6h', cache='Redis', time='1ms' (CHI::Driver::_log_set_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1226) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='httpd.portal', key='session:302432a3efad', size=3166, expires='6h', cache='Redis', time='0ms' (CHI::Driver::_log_set_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:unknown] Adding session parameter from dispatcher session to Catalyst session : _client_mac : 30:24:32:a3:ef:ad (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:unknown] Matched IP '10.10.10.145' to MAC address '30:24:32:a3:ef:ad' using SQL 'ip4log' table (pf::ip4log::ip2mac) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='httpd.portal', key='session:302432a3efad', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::Portal::Session object (pf::Portal::Session::new) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] using session id 'b21929f60cb26fe36e48926c33f1903c' (pf::Portal::Session::_initialize) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='httpd.portal', key='b21929f60cb26fe36e48926c33f1903c', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Authorized locale(s) are en_US (pf::Portal::Session::getLanguages) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] locale from the browser is en_US (pf::Portal::Session::getLanguages) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Setting locale to en_US (pf::Portal::Session::_initializeI18n) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _client_ip : 192.168.20.97 (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _destination_url : http://www.packetfence.org/ (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _grant_url : undef (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _client_mac : 30:24:32:a3:ef:ad (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Adding session parameter from dispatcher session to Catalyst session : _profile : pf::Connection::Profile=HASH(0x55c560067c38) (captiveportal::PacketFence::Model::Portal::Session::_build_dispatcherSession) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='httpd.portal', key='b21929f60cb26fe36e48926c33f1903c', size=1577, expires='6h', cache='Redis', time='0ms' (CHI::Driver::_log_set_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Remote Address is 10.10.10.145. Client is behind proxy? Returning: 10.10.10.145 according to HTTP Headers (captiveportal::PacketFence::Model::Portal::Session::_build_clientIP) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Trying to match MAC address to IP '10.10.10.145' using SQL 'ip4log' table (pf::ip4log::ip2mac) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Viewing an 'ip4log' table entry for the following IP address '10.10.10.145' (pf::ip4log::_view_by_ip) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Matched IP '10.10.10.145' to MAC address '30:24:32:a3:ef:ad' using SQL 'ip4log' table (pf::ip4log::ip2mac) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) INFO: [mac:30:24:32:a3:ef:ad] Instantiate profile default (pf::Connection::ProfileFactory::_from_profile) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::Connection::Profile object (pf::Connection::Profile::new) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Authorized locale(s) are en_US (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] locale from the browser is en_US (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] locale from the browser en is not supported (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Language locale from the browser en_US is not supported (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Language locale from the browser en is not supported (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] prefered user languages are en_US (captiveportal::PacketFence::Controller::Root::getLanguages) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Setting locale to en_US (captiveportal::PacketFence::Controller::Root::setupLanguage) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='httpd.portal', key='user_session:f32837e39b8e178015b16fd38d7e5692ab2122b8', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_blackhole_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Building Authentication Choice module using sources : (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Choice::BUILD) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_oauth_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Building Authentication Choice module using sources : (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Choice::BUILD) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_guest_policy is using sources : null (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Building Authentication Choice module using sources : null (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Choice::BUILD) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_login_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_billing_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Module default_policy+default_registration_policy+default_saml_policy is using sources : (captiveportal::Role::MultiSource::_build_sources) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Building Authentication Choice module using sources : (captiveportal::PacketFence::DynamicRouting::Module::Authentication::Choice::BUILD) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Destination is : https://nac1.bluedogrv.lan/?cmd (captiveportal::PacketFence::DynamicRouting::Application::process_destination_url) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='fingerbank::Config::read_config', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='fingerbank::Config::read_config-cached_at', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='fingerbank::Config::read_config', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='fingerbank::Config::read_config-cached_at', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='fingerbank', key='pf::fingerbank::endpoint_attributes::request::30:24:32:a3:ef:ad', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='Default', key='HASH(0x55c5592f65f0)', cache='RawMemory', time='0ms': MISS (not in cache) (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='Default', key='{"server":" 127.0.0.1:6380"}', size=1, expires='never', cache='RawMemory', time='0ms' (CHI::Driver::_log_set_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] checking handle (pf::db::is_old_connection_good) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] we are currently connected (pf::db::is_old_connection_good) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] not checking db handle, it has been less than 30 sec from last connection (pf::db::is_old_connection_good) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] No wsrep provider so considering wsrep as healthy (pf::db::db_wsrep_healthy) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Setting current module id : default_policy (captiveportal::PacketFence::DynamicRouting::Application::current_module_id) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /record_destination_url matches /status/billing (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /record_destination_url matches /billing.* (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /record_destination_url matches /logout (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /record_destination_url matches /access (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Checking if /record_destination_url matches /record_destination_url (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Found a route match : /record_destination_url (captiveportal::Role::Routed::path_method) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Setting previous module id : default_policy (captiveportal::PacketFence::DynamicRouting::Application::previous_module_id) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='httpd.portal', key='user_session:f32837e39b8e178015b16fd38d7e5692ab2122b8', size=30, expires='6h', cache='Redis', time='0ms' (CHI::Driver::_log_set_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache get for namespace='httpd.portal', key='expires:302432a3efad', cache='Redis', time='0ms': HIT (CHI::Driver::_log_get_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='httpd.portal', key='expires:302432a3efad', size=24, expires='6h', cache='Redis', time='0ms' (CHI::Driver::_log_set_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] cache set for namespace='httpd.portal', key='session:302432a3efad', size=3065, expires='6h', cache='Redis', time='0ms' (CHI::Driver::_log_set_result) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:47:37 NAC1 packetfence_httpd.portal: httpd.portal(1230) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:47:45 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:47:45 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:47:45 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) Mar 11 09:47:45 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] hitting handler with URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) (pf::web::dispatcher::_handler) Mar 11 09:47:45 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 09:47:45 NAC1 packetfence_httpd.portal: httpd.portal(1228) DEBUG: [mac:30:24:32:a3:ef:ad] URI '/captive-portal' (URL: http://NAC1.bluedogrv.lan/captive-portal) is properly handled and should now continue to the captive-portal / Catalyst (pf::web::dispatcher::_handler) ___________________________________________END OF FIRST LOG hitting handler with URI '/Aruba::Instant_Access' (URL: http://nac1.bluedogrv.lan/Aruba::Instant_Access) (pf::web::dispatcher::_handler) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::filter (pf::web::filter::new) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] checking handle (pf::db::is_old_connection_good) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] we are currently connected (pf::db::is_old_connection_good) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] not checking db handle, it has been less than 30 sec from last connection (pf::db::is_old_connection_good) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] No wsrep provider so considering wsrep as healthy (pf::db::db_wsrep_healthy) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] We set the destination URL to http://nac1.bluedogrv.lan/Aruba::Instant_Access for further usage (pf::web::dispatcher::_handler) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::inline object (pf::inline::new) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Instantiate a new iptables modification method. pf::ipset (pf::inline::get_technique) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::iptables object (pf::iptables::new) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::web::externalportal (pf::web::externalportal::new) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] instantiating new pf::access_filter::switch (pf::access_filter::new) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] No engine found for external_portal (pf::access_filter::test) Mar 11 10:03:57 NAC1 packetfence_httpd.portal: httpd.portal(1227) DEBUG: [mac:30:24:32:a3:ef:ad] Tested URI '/Aruba::Instant_Access' against external portal mechanism and does not appear to be one. (pf::web::externalportal::handle) and the page just says NOT IMPLEMENTED GET to /Aruba::Instant_Access not supported. On Wed, Mar 11, 2020 at 9:07 AM Zacharry Williams <[email protected]> wrote: > Okay so this is the one from today. get's matched to the Ethernet profile > and denied. > > > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) INFO: > [mac:00:24:d7:90:be:84] handling radius autz request: from switch_ip => > (192.168.100.216), connection_type => Wireless-802.11-EAP,switch_mac => > (c8:b5:ad:ce:43:7c), mac => [00:24:d7:90:be:84], port => 0, username => > "host/ tacos -016.BluedogRV.lan" (pf::radius::authorize) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) INFO: > [mac:00:24:d7:90:be:84] is doing machine auth with account 'host/ tacos . > tacos.lan'. (pf::radius::authorize) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] instantiating new pf::role object (pf::role::new) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] instantiating new pf::access_filter::vlan > (pf::access_filter::new) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] No engine found for IsPhone > (pf::access_filter::test) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Trying to match IP address to MAC > '00:24:d7:90:be:84' using SQL 'ip4log' table (pf::ip4log::mac2ip) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Viewing an 'ip4log' table entry for the following > MAC address '00:24:d7:90:be:84' (pf::ip4log::_view_by_mac) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Matched MAC '00:24:d7:90:be:84' to IP address > '192.168.50.119' using SQL 'ip4log' table (pf::ip4log::mac2ip) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Memory configuration is not valid anymore for key > FilterEngine::Profile() in local cached_hash (pfconfig::cached::is_valid) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Memory configuration is not valid anymore for key > config::Profiles() in local cached_hash (pfconfig::cached::is_valid) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) INFO: > [mac:00:24:d7:90:be:84] Instantiate profile Ethernet802.1x > (pf::Connection::ProfileFactory::_from_profile) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] instantiating new pf::Connection::Profile object > (pf::Connection::Profile::new) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] instantiating new pf::access_filter::vlan > (pf::access_filter::new) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] No engine found for AutoRegister > (pf::access_filter::test) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Autoregistration set on profile Ethernet802.1x > (pf::role::shouldAutoRegister) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] instantiating new pf::access_filter::vlan > (pf::access_filter::new) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] No engine found for NodeInfoForAutoReg > (pf::access_filter::test) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Memory configuration is not valid anymore for key > config::Profiles() in local cached_hash (pfconfig::cached::is_valid) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Used realm tacos tacos.lan is associated to the > configured realm tacos.lan > (pf::config::util::get_realm_authentication_source) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) INFO: > [mac:00:24:d7:90:be:84] Found authentication source(s) : 'tacod1' for realm > ' tacos.lan' (pf::config::util::filter_authentication_sources) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] EAP connection with a username "host/ tacos -016. > tacos .lan". Trying to match rules from authentication sources. > (pf::role::getNodeInfoForAutoReg) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) WARN: > [mac:00:24:d7:90:be:84] Use of uninitialized value in concatenation (.) or > string at /usr/local/pf/lib/pf/authentication.pm line 389. > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Match called with parameters radius_request => > HASH(0x55bbf87d1a00), rule_class => authentication, stripped_user_name => , > SSID => , username => host/tacos-016. tacos .lan, realm => BluedogRV.lan, > context => radius, connection_type => Wireless-802.11-EAP > (pf::authentication::match2) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] Stripping username is enabled in this context > (radius). Will return a split username and realm. > (pf::config::util::strip_username_if_needed) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) INFO: > [mac:00:24:d7:90:be:84] Using sources tacos for matching > (pf::authentication::match2) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) INFO: > [mac:00:24:d7:90:be:84] LDAP testing connection (pf::LDAP::expire_if) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] cache get for namespace='Default', > key='ARRAY(0x55bbfd640658)', cache='RawMemory', time='0ms': HIT > (CHI::Driver::_log_get_result) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] [ tacos ] Using LDAP connection to 192.168.20.98 > (pf::Authentication::Source::LDAPSource::_connect) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] [ tacos tacos ] Searching for > (|(sAMAccountName=host/ tacos -016. tacos .lan)(servicePrincipalName=host/ > tacos -016. tacos .lan)), from DC= tacos ,DC=lan, with scope sub > (pf::Authentication::Source::LDAPSource::match_in_subclass) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] [ tacos tacos ] Found 1 results > (pf::Authentication::Source::LDAPSource::_match_in_subclass) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] [ tacos tacos ] Searching is_member filter > (|(member=CN= tacos -016,OU=Post Falls,OU= tacos Computers,DC= tacos > ,DC=lan)(uniqueMember=CN= tacos -016,OU=Post Falls,OU= tacos Computers,DC= > tacos ,DC=lan)(memberUid=)) > (pf::Authentication::Source::LDAPSource::_match_in_subclass) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] [ tacos Domain_Users] Searching for > (|(sAMAccountName=host/ tacos -016. tacos .lan)(servicePrincipalName=host/ > tacos -016. tacos .lan)), from DC= tacos ,DC=lan, with scope sub > (pf::Authentication::Source::LDAPSource::match_in_subclass) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] [ tacos Domain_Users] Found 1 results > (pf::Authentication::Source::LDAPSource::_match_in_subclass) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] [ tacos Domain_Users] Searching is_member filter > (|(member=CN= tacos -016,OU=Post Falls,OU= tacos Computers,DC= tacos > ,DC=lan)(uniqueMember=CN= tacos -016,OU=Post Falls,OU= tacos Computers,DC= > tacos ,DC=lan)(memberUid=)) > (pf::Authentication::Source::LDAPSource::_match_in_subclass) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) WARN: > [mac:00:24:d7:90:be:84] No category computed for autoreg > (pf::role::getNodeInfoForAutoReg) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] [00:24:d7:90:be:84] auto-registering node > (pf::radius::authorize) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) WARN: > [mac:00:24:d7:90:be:84] No role specified or found for pid host/ tacos > -016.BluedogRV.lan (MAC 00:24:d7:90:be:84); assume maximum number of > registered nodes is reached (pf::node::is_max_reg_nodes_reached) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) ERROR: > [mac:00:24:d7:90:be:84] max nodes per pid met or exceeded - registration of > 00:24:d7:90:be:84 to host/ tacos -016.BluedogRV.lan failed > (pf::registration::setup_node_for_registration) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) ERROR: > [mac:00:24:d7:90:be:84] auto-registration of node failed max nodes per pid > met or exceeded (pf::radius::authorize) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) ERROR: > [mac:00:24:d7:90:be:84] Database query failed with non retryable error: > Cannot add or update a child row: a foreign key constraint fails > (`pf`.`node`, CONSTRAINT `0_57` FOREIGN KEY (`tenant_id`, `pid`) REFERENCES > `person` (`tenant_id`, `pid`) ON DELETE CASCADE ON UPDATE CASCADE) (errno: > 1452) [INSERT INTO `node` ( `autoreg`, `bandwidth_balance`, > `bypass_role_id`, `bypass_vlan`, `category_id`, `computername`, > `detect_date`, `device_class`, `device_manufacturer`, `device_score`, > `device_type`, `device_version`, `dhcp6_enterprise`, `dhcp6_fingerprint`, > `dhcp_fingerprint`, `dhcp_vendor`, `last_arp`, `last_dhcp`, `last_seen`, > `lastskip`, `mac`, `machine_account`, `notes`, `pid`, `regdate`, > `sessionid`, `status`, `tenant_id`, `time_balance`, `unregdate`, > `user_agent`, `voip`) VALUES ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, > ?, ?, ?, NOW(), ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ? ) ON DUPLICATE KEY > UPDATE `autoreg` = ?, `last_seen` = NOW(), `machine_account` = ?, `pid` = > ?, `status` = ?, `tenant_id` = ?]{yes, NULL, NULL, NULL, NULL, NULL, > 2020-03-11 08:53:16, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, > 0000-00-00 00:00:00, 0000-00-00 00:00:00, 0000-00-00 00:00:00, > 00:24:d7:90:be:84, host/ tacos -016.BluedogRV.lan, NULL, host/ tacos > -016.BluedogRV.lan, 0000-00-00 00:00:00, NULL, reg, 1, NULL, 0000-00-00 > 00:00:00, NULL, no, yes, host/ tacos -016. tacos .lan, host/ tacos > -016.BluedogRV.lan, reg, 1} (pf::dal::db_execute) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) DEBUG: > [mac:00:24:d7:90:be:84] disconnecting db (pf::db::db_disconnect) > Mar 11 08:57:01 NAC1 packetfence_httpd.aaa: httpd.aaa(9641) ERROR: > [mac:00:24:d7:90:be:84] Cannot save 00:24:d7:90:be:84 error (500) > (pf::radius::authorize) > > # > # Copyright (C) 2005-2019 Inverse inc. > # > # See the enclosed file COPYING for license information (GPL). > # If you did not receive this file, see > # http://www.fsf.org/licensing/licenses/gpl.html > [default] > sources=null > > [Wire_noEAP] > locale= > filter=connection_type:Ethernet-NoEAP > autoregister=enabled > > [Wireless_EAP] > filter_match_style=all > description=Wireless_EAP > sources=tacos-MachineAuth > filter=connection_type:Wireless-802.11-EAP,ssid:tacos > autoregister=enabled > redirecturl=https://www.tacos.com > logo=/common/Logo-horz.png > > # > # Copyright (C) 2005-2019 Inverse inc. > # > # See the enclosed file COPYING for license information (GPL). > # If you did not receive this file, see > # http://www.fsf.org/licensing/licenses/gpl.html > [Ethernet802.1x] > filter=connection_type:Ethernet-EAP,connection_sub_type:MS-CHAP-V2 > sources=BDRVDC1 > unreg_on_acct_stop=enabled > autoregister=enabled > > [Wireless_BYOD] > filter_match_style=all > description=Wireless_EAP > sources=BDRVDC1 > filter=connection_type:Wireless-802.11-EAP,ssid:tacos-BYOD > autoregister=enabled > logo=/common/Logo-horz.png > redirecturl=https://www.tacos.com > # > # Copyright (C) 2005-2019 Inverse inc. > # > # See the enclosed file COPYING for license information (GPL). > # If you did not receive this file, see > # http://www.fsf.org/licensing/licenses/gpl.html > ~ > ~ > ~ > ~ > ~ > ~ > ~ > > On Wed, Mar 11, 2020 at 8:48 AM Zacharry Williams <[email protected]> > wrote: > >> Yep I'm scrubbing them now. It's also matching clients connecting on >> wireless-eap to wired-eap >> >> On Tue, Mar 10, 2020, 4:53 PM Durand fabrice via PacketFence-users < >> [email protected]> wrote: >> >>> Hello, >>> >>> can you provide the packetfence.log file and the profiles.conf file ? >>> >>> Regards >>> >>> Fabrice >>> >>> >>> Le 20-03-10 à 15 h 19, Zacharry Williams via PacketFence-users a écrit : >>> >>> Hey all, >>> >>> Randomly it matched the correct connection profile, one time. Is this >>> like a 9.3 bug where connection profiles aren't being match? >>> >>> On Mon, Mar 9, 2020 at 3:06 PM Zacharry Williams <[email protected]> >>> wrote: >>> >>>> Hey all, >>>> >>>> I've been working on setting up a guest LAN and a byod LAN for a few >>>> days now. When I use a PSK or AD Authentication it works fine, but the >>>> captive portal isn't working like I think it should be. >>>> I revisited the guide a few times to check and I don't think i'm >>>> missing any settings. I customized a captive portal with a logo and an >>>> acceptable use policy but every time I get the captive portal, I don't get >>>> the portal I customized but instead get the default one. It's like the >>>> default connection profile is matched first. I set the httpd.aaa.conf >>>> logging to debug but nothing shows up as to why it's picking that >>>> connection profile in packetfence.log. I'm using Aruba instants, and >>>> managing them through Aruba Central. >>>> >>>> Where are the logs to read into why it's picking that portal? >>>> >>>> >>> >>> _______________________________________________ >>> PacketFence-users mailing >>> [email protected]https://lists.sourceforge.net/lists/listinfo/packetfence-users >>> >>> _______________________________________________ >>> PacketFence-users mailing list >>> [email protected] >>> https://lists.sourceforge.net/lists/listinfo/packetfence-users >>> >>
_______________________________________________ PacketFence-users mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/packetfence-users
