Okay, So we have been doing some testing on a pristine 12.1, and the behaviour is the same. It seems that a couple of things are occurring with at least one problem client, an iPhone 12 Pro. Maybe we broke our config somewhere along the way with updates/upgrades and did not realize it, or Apple changed things to break our config, as I am fairly certain these devices were working a couple years ago during tests.
1) They are disconnecting and reconnecting in the same second. Tue Jan 17 15:36:56 2023 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED f2:ef:bb:22:8c:62 Tue Jan 17 15:36:56 2023 daemon.notice hostapd: wlan0: AP-STA-CONNECTED f2:ef:bb:22:8c:62 So while we have network_redirect_delay=25s, this only controls the graphics in the captive portal login page after submitting an email for authorization. The actual RADIUS Disconnect-Request is fired off immediately as the page with the delay-progress-bar appears, and so our hostapd daemon has not changed the VLAN internally before the device is reconnected, and the client ends up back on the registration VLAN instead of the default VLAN. PF sees this as indicated by this log, which causes the device to be disconnected again, a proactive mechanism we did not really know existed, but makes sense Jan 17 15:37:43 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Device is registered and still on the portal, attempting to release it again. (captiveportal::PacketFence::DynamicRouting::Module::Root::unknown_state) Jan 17 15:37:44 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] re-evaluating access (manage_register called) (pf::enforcement::reevaluate_access) Jan 17 15:37:44 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] VLAN reassignment is forced. (pf::enforcement::_should_we_reassign_vlan) 2) Unfortunately, at this point this iPhone 12 Pro is still on the portal, showing an error and is not detecting Internet. So it has ended up on the right VLAN now, but thinks there is a problem and the user has to cancel the login and forceably accept to connected to a network without Internet in order to proceed. This incorrect detection we also do not really understand. Diego suggested that a URL fed from the Registration network DHCP server should have allowed the device to learn it has Internet per rfc7710bis / rfc8910 . Below are the logs from our AP, and the TCPdump of the matching Radius between the AP and PF server on the management network and the packetfence.log from that period. There is one WARN we do not understand at all: Jan 17 15:36:56 pf4 pfqueue[27836]: pfqueue(27836) WARN: [mac:f2:ef:bb:22:8c:62] Warning: 1366: Incorrect string value: '\x98\xD1Mk\xF9\xC3...' for column `pf`.`radius_audit_log`.`radius_reply` at row 1 (pf::dal::db_execute All to say we could use any insights on these device behaviours to get them working with the Captive Portal again cheers, Ian Tue Jan 17 15:36:32 2023 daemon.notice hostapd: wlan0: AP-STA-CONNECTED f2:ef:bb:22:8c:62 Tue Jan 17 15:36:32 2023 daemon.info hostapd: wlan0: STA f2:ef:bb:22:8c:62 RADIUS: starting accounting session E20B8427B183BCA8 Tue Jan 17 15:36:56 2023 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED f2:ef:bb:22:8c:62 Tue Jan 17 15:36:56 2023 daemon.info hostapd: wlan0: STA f2:ef:bb:22:8c:62 RADIUS: stopped accounting session E20B8427B183BCA8 Tue Jan 17 15:36:56 2023 daemon.info hostapd: wlan0: STA f2:ef:bb:22:8c:62 RADIUS: VLAN ID 81 Tue Jan 17 15:36:56 2023 daemon.info hostapd: wlan0: STA f2:ef:bb:22:8c:62 IEEE 802.11: authenticated Tue Jan 17 15:36:56 2023 daemon.info hostapd: wlan0: STA f2:ef:bb:22:8c:62 IEEE 802.11: associated (aid 2) Tue Jan 17 15:36:56 2023 daemon.notice hostapd: wlan0: AP-STA-CONNECTED f2:ef:bb:22:8c:62 Tue Jan 17 15:36:56 2023 daemon.info hostapd: wlan0: STA f2:ef:bb:22:8c:62 RADIUS: starting accounting session E20B8427B183BCA8 Tue Jan 17 15:37:45 2023 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED f2:ef:bb:22:8c:62 Tue Jan 17 15:37:45 2023 daemon.info hostapd: wlan0: STA f2:ef:bb:22:8c:62 RADIUS: stopped accounting session E20B8427B183BCA8 Tue Jan 17 15:37:45 2023 daemon.info hostapd: wlan0: STA f2:ef:bb:22:8c:62 RADIUS: VLAN ID 83 15:36:32.186127 IP 10.2.1.11.51167 > 10.2.1.2.1812: RADIUS, Access-Request (1), id: 0x3e length: 164 15:36:32.219186 IP 10.2.1.2.1812 > 10.2.1.11.51167: RADIUS, Access-Accept (2), id: 0x3e length: 36 15:36:32.229185 IP 10.2.1.11.51513 > 10.2.1.2.1813: RADIUS, Accounting-Request (4), id: 0x3f length: 182 15:36:32.229653 IP 10.2.1.2.1813 > 10.2.1.11.51513: RADIUS, Accounting-Response (5), id: 0x3f length: 35 15:36:56.367141 IP 10.2.1.2.55433 > 10.2.1.11.3799: RADIUS, Disconnect-Request (40), id: 0x31 length: 39 15:36:56.370736 IP 10.2.1.11.51513 > 10.2.1.2.1813: RADIUS, Accounting-Request (4), id: 0x40 length: 224 15:36:56.371282 IP 10.2.1.2.1813 > 10.2.1.11.51513: RADIUS, Accounting-Response (5), id: 0x40 length: 35 15:36:56.371388 IP 10.2.1.11.3799 > 10.2.1.2.55433: RADIUS, Disconnect-ACK (41), id: 0x31 length: 44 15:36:56.542763 IP 10.2.1.11.51513 > 10.2.1.2.1813: RADIUS, Accounting-Request (4), id: 0x41 length: 182 15:36:56.543252 IP 10.2.1.2.1813 > 10.2.1.11.51513: RADIUS, Accounting-Response (5), id: 0x41 length: 35 15:37:45.263742 IP 10.2.1.2.41387 > 10.2.1.11.3799: RADIUS, Disconnect-Request (40), id: 0xf4 length: 39 15:37:45.265149 IP 10.2.1.11.51513 > 10.2.1.2.1813: RADIUS, Accounting-Request (4), id: 0x42 length: 224 15:37:45.265408 IP 10.2.1.11.3799 > 10.2.1.2.41387: RADIUS, Disconnect-ACK (41), id: 0xf4 length: 44 15:37:45.265869 IP 10.2.1.2.1813 > 10.2.1.11.51513: RADIUS, Accounting-Response (5), id: 0x42 length: 35 15:37:45.385692 IP 10.2.1.11.51167 > 10.2.1.2.1812: RADIUS, Access-Request (1), id: 0x43 length: 164 15:37:45.428970 IP 10.2.1.2.1812 > 10.2.1.11.51167: RADIUS, Access-Accept (2), id: 0x43 length: 36 15:37:45.582392 IP 10.2.1.11.51513 > 10.2.1.2.1813: RADIUS, Accounting-Request (4), id: 0x44 length: 182 15:37:45.584029 IP 10.2.1.2.1813 > 10.2.1.11.51513: RADIUS, Accounting-Response (5), id: 0x44 length: 35 Jan 17 15:36:32 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] handling radius autz request: from switch_ip => (10.2.1.11), connection_type => Wireless-802.11-NoEAP,switch_mac => (ec:08:6b:6a:63:5a), mac => [f2:ef:bb:22:8c:62], port => 0, username => "f2efbb228c62", ssid => TestOne_WiFi (pf::radius::authorize) Jan 17 15:36:32 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:36:32 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] is of status unreg; belongs into registration VLAN (pf::role::getRegistrationRole) Jan 17 15:36:32 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] (10.2.1.11) Added VLAN 81 to the returned RADIUS Access-Accept (pf::Switch::returnRadiusAccessAccept) Jan 17 15:36:32 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Updating locationlog from accounting request (pf::api::handle_accounting_metadata) Jan 17 15:36:32 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) WARN: [mac:f2:ef:bb:22:8c:62] Cannot find any combination ID in any schemas (fingerbank::Source::LocalDB::_getCombinationID) Jan 17 15:36:32 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Upstream is configured and unable to fullfil an exact match locally. Will ignore result from local database (fingerbank::Source::LocalDB::match) Jan 17 15:36:32 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Successfully interrogate upstream Fingerbank project for matching. Got device : 264 (fingerbank::Source::Collector::match) Jan 17 15:36:32 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:36:34 pf4 pfqueue[23216]: pfqueue(23216) INFO: [mac:f2:ef:bb:22:8c:62] Sending a firewall SSO 'Update' request for MAC 'f2:ef:bb:22:8c:62' and IP '10.2.2.149' (pf::firewallsso::do_sso) Jan 17 15:36:34 pf4 pfqueue[27760]: pfqueue(27760) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:36:38 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(14) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:36:38 pf4 pfqueue[23622]: pfqueue(23622) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:36:38 pf4 pfqueue[23622]: pfqueue(23622) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:36:38 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:36:49 pf4 pfqueue[23622]: pfqueue(23622) INFO: [mac:f2:ef:bb:22:8c:62] Sending a firewall SSO 'Update' request for MAC 'f2:ef:bb:22:8c:62' and IP '10.2.2.149' (pf::firewallsso::do_sso) Jan 17 15:36:49 pf4 pfqueue[27817]: pfqueue(27817) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:36:49 pf4 pfqueue[23215]: pfqueue(23215) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] User endu...@gmail.com has authenticated on the portal. (captiveportal::PacketFence::DynamicRouting::Module::_username_set) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] new activation code successfully generated (pf::activation::create) Jan 17 15:36:55 pf4 pfqueue[23215]: pfqueue(23215) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) WARN: [mac:f2:ef:bb:22:8c:62] Calling match with empty/invalid rule class. Defaulting to 'authentication' (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Using sources email for matching (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match_rule) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) WARN: [mac:f2:ef:bb:22:8c:62] Calling match with empty/invalid rule class. Defaulting to 'authentication' (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Using sources email for matching (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match_rule) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Using sources email for matching (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) WARN: [mac:f2:ef:bb:22:8c:62] Calling match with empty/invalid rule class. Defaulting to 'authentication' (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Using sources email for matching (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match_rule) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) WARN: [mac:f2:ef:bb:22:8c:62] Calling match with empty/invalid rule class. Defaulting to 'authentication' (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Using sources email for matching (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match_rule) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) WARN: [mac:f2:ef:bb:22:8c:62] Calling match with empty/invalid rule class. Defaulting to 'authentication' (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Using sources email for matching (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match_rule) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) WARN: [mac:f2:ef:bb:22:8c:62] Calling match with empty/invalid rule class. Defaulting to 'authentication' (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Using sources email for matching (pf::authentication::match) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match_rule) Jan 17 15:36:54 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Matched rule (catchall) in source email, returning actions. (pf::Authentication::Source::match) Jan 17 15:36:55 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] security_event 1300003 force-closed for f2:ef:bb:22:8c:62 (pf::security_event::security_event_force_close) Jan 17 15:36:55 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:36:55 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:36:55 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) WARN: [mac:f2:ef:bb:22:8c:62] locale from the URL is not supported (captiveportal::PacketFence::Controller::Root::getLanguages) Jan 17 15:36:55 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] Releasing device (captiveportal::PacketFence::DynamicRouting::Module::Root::release) Jan 17 15:36:55 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] re-evaluating access (manage_register called) (pf::enforcement::reevaluate_access) Jan 17 15:36:55 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:36:55 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] VLAN reassignment is forced. (pf::enforcement::_should_we_reassign_vlan) Jan 17 15:36:55 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] switch port is (10.2.1.11) ifIndex 0connection type: WiFi MAC Auth (pf::enforcement::_vlan_reevaluation) Jan 17 15:36:55 pf4 pfqueue[23028]: pfqueue(23028) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:36:56 pf4 pfqueue[27836]: pfqueue(27836) INFO: [mac:f2:ef:bb:22:8c:62] [f2:ef:bb:22:8c:62] DesAssociating mac on switch (10.2.1.11) (pf::api::desAssociate) Jan 17 15:36:56 pf4 pfqueue[27836]: pfqueue(27836) INFO: [mac:f2:ef:bb:22:8c:62] deauthenticating f2:ef:bb:22:8c:62 (pf::Switch::Hostapd::radiusDisconnect) Jan 17 15:36:56 pf4 pfqueue[27836]: pfqueue(27836) INFO: [mac:f2:ef:bb:22:8c:62] Will be using connnector local_connector to perform the deauth (pf::Switch::radius_deauth_connection_info) Jan 17 15:36:56 pf4 pfqueue[27836]: pfqueue(27836) WARN: [mac:f2:ef:bb:22:8c:62] Warning: 1366: Incorrect string value: '\x98\xD1Mk\xF9\xC3...' for column `pf`.`radius_audit_log`.`radius_reply` at row 1 (pf::dal::db_execute) Jan 17 15:36:56 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Updating locationlog from accounting request (pf::api::handle_accounting_metadata) Jan 17 15:37:04 pf4 pfqueue[23327]: pfqueue(23327) INFO: [mac:f2:ef:bb:22:8c:62] Sending a firewall SSO 'Update' request for MAC 'f2:ef:bb:22:8c:62' and IP '10.2.2.149' (pf::firewallsso::do_sso) Jan 17 15:37:05 pf4 pfqueue[27867]: pfqueue(27867) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:37:05 pf4 pfqueue[23215]: pfqueue(23215) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:37:19 pf4 pfqueue[23283]: pfqueue(23283) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:37:20 pf4 pfperl-api-docker-wrapper[1114]: pfperl-api(17) INFO: [mac:[undef]] getting security_events triggers for accounting cleanup (pf::accounting::acct_maintenance) Jan 17 15:37:20 pf4 pfqueue[23728]: pfqueue(23728) INFO: [mac:f2:ef:bb:22:8c:62] Sending a firewall SSO 'Update' request for MAC 'f2:ef:bb:22:8c:62' and IP '10.2.2.149' (pf::firewallsso::do_sso) Jan 17 15:37:20 pf4 pfqueue[27922]: pfqueue(27922) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:37:21 pf4 pfperl-api-docker-wrapper[1114]: pfperl-api(17) INFO: [mac:[undef]] Using 300 resolution threshold (pf::pfcron::task::cluster_check::run) Jan 17 15:37:21 pf4 pfperl-api-docker-wrapper[1114]: pfperl-api(17) INFO: [mac:[undef]] All cluster members are running the same configuration version (pf::pfcron::task::cluster_check::run) Jan 17 15:37:21 pf4 pfperl-api-docker-wrapper[1114]: pfperl-api(19) INFO: [mac:[undef]] processed 0 security_events during security_event maintenance (1673987841.17583 1673987841.18979) (pf::security_event::security_event_maintenance) Jan 17 15:37:34 pf4 pfqueue[23131]: pfqueue(23131) INFO: [mac:f2:ef:bb:22:8c:62] Sending a firewall SSO 'Update' request for MAC 'f2:ef:bb:22:8c:62' and IP '10.2.2.149' (pf::firewallsso::do_sso) Jan 17 15:37:34 pf4 pfqueue[27982]: pfqueue(27982) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:37:34 pf4 pfqueue[23283]: pfqueue(23283) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:37:43 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:37:43 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(16) INFO: [mac:f2:ef:bb:22:8c:62] Device is registered and still on the portal, attempting to release it again. (captiveportal::PacketFence::DynamicRouting::Module::Root::unknown_state) Jan 17 15:37:44 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:37:44 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) WARN: [mac:f2:ef:bb:22:8c:62] locale from the URL is not supported (captiveportal::PacketFence::Controller::Root::getLanguages) Jan 17 15:37:44 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] Releasing device (captiveportal::PacketFence::DynamicRouting::Module::Root::release) Jan 17 15:37:44 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] re-evaluating access (manage_register called) (pf::enforcement::reevaluate_access) Jan 17 15:37:44 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:37:44 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] VLAN reassignment is forced. (pf::enforcement::_should_we_reassign_vlan) Jan 17 15:37:44 pf4 httpd.portal-docker-wrapper[3718]: httpd.portal(15) INFO: [mac:f2:ef:bb:22:8c:62] switch port is (10.2.1.11) ifIndex 0connection type: WiFi MAC Auth (pf::enforcement::_vlan_reevaluation) Jan 17 15:37:44 pf4 pfqueue[23283]: pfqueue(23283) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:37:44 pf4 pfqueue[23264]: pfqueue(23264) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Jan 17 15:37:45 pf4 pfqueue[28015]: pfqueue(28015) INFO: [mac:f2:ef:bb:22:8c:62] [f2:ef:bb:22:8c:62] DesAssociating mac on switch (10.2.1.11) (pf::api::desAssociate) Jan 17 15:37:45 pf4 pfqueue[28015]: pfqueue(28015) INFO: [mac:f2:ef:bb:22:8c:62] deauthenticating f2:ef:bb:22:8c:62 (pf::Switch::Hostapd::radiusDisconnect) Jan 17 15:37:45 pf4 pfqueue[28015]: pfqueue(28015) INFO: [mac:f2:ef:bb:22:8c:62] Will be using connnector local_connector to perform the deauth (pf::Switch::radius_deauth_connection_info) Jan 17 15:37:45 pf4 pfqueue[28015]: pfqueue(28015) WARN: [mac:f2:ef:bb:22:8c:62] Warning: 1366: Incorrect string value: '\x96\x88o\x8F\xBC7...' for column `pf`.`radius_audit_log`.`radius_reply` at row 1 (pf::dal::db_execute) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] handling radius autz request: from switch_ip => (10.2.1.11), connection_type => Wireless-802.11-NoEAP,switch_mac => (ec:08:6b:6a:63:5a), mac => [f2:ef:bb:22:8c:62], port => 0, username => "f2efbb228c62", ssid => TestOne_WiFi (pf::radius::authorize) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Instantiate profile Test_WiFi (pf::Connection::ProfileFactory::_from_profile) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Found authentication source(s) : '' for realm 'null' (pf::config::util::filter_authentication_sources) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Connection type is MAC-AUTH. Getting role from node_info (pf::role::getRegisteredRole) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Username was defined "f2efbb228c62" - returning role 'guest' (pf::role::getRegisteredRole) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] PID: "endu...@gmail.com", Status: reg Returned VLAN: (undefined), Role: guest (pf::role::fetchRoleForNode) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] (10.2.1.11) Added VLAN 83 to the returned RADIUS Access-Accept (pf::Switch::returnRadiusAccessAccept) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Updating locationlog from accounting request (pf::api::handle_accounting_metadata) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) WARN: [mac:f2:ef:bb:22:8c:62] Cannot find any combination ID in any schemas (fingerbank::Source::LocalDB::_getCombinationID) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Upstream is configured and unable to fullfil an exact match locally. Will ignore result from local database (fingerbank::Source::LocalDB::match) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) INFO: [mac:f2:ef:bb:22:8c:62] Successfully interrogate upstream Fingerbank project for matching. Got device : 264 (fingerbank::Source::Collector::match) Jan 17 15:37:45 pf4 httpd.aaa-docker-wrapper[2464]: httpd.aaa(8) WARN: [mac:f2:ef:bb:22:8c:62] Unable to pull accounting history for device f2:ef:bb:22:8c:62. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) On Wed, Jan 11, 2023 at 3:09 PM Diego Garcia del Rio <garc...@gmail.com> wrote: > im Guessing it might be related to the rfc7710bis / rfc8910 portal support > > this means that via dhcp, the client is provided with an URL they can use > to check the status of the device in the portal (whether they are still > jailed or no) > > normally this information is served on the same interface as the portal if > im not mistaken. you might want to check the logs for pf.log or the > haproxy-portal log for urls matching "/rfc7710" > > if so.. it might be that the clients are too fast re-accessing that url > and determining they are still locked > > in my case, forcing a disconnect via the COA will cause the client to > re-issue a dhcp request.. and thus, a new portal request? > > > > > On Wed, Jan 11, 2023 at 2:36 PM Ian MacDonald via PacketFence-users < > packetfence-users@lists.sourceforge.net> wrote: > >> Daniel, >> >> The random MAC would seem like an obvious culprit, but it is not. >> >> On an iPhone, if you click on the little "i" for information next to each >> connection, you see that the OS uses the same [random] mac per SSID, so it >> will never change for a given WiFi network after is has connected. It will >> be different for each SSID/network. >> >> Since it does not change per SSID, the MAC can be used for auth, but >> obviously the OUI will no longer indicate it is an Apple device. >> >> cheers, >> Ian >> >> >> On Wed, Jan 11, 2023 at 11:48 AM Daniel Silva <dan...@unifor.br> wrote: >> >>> Good afternoon, >>> >>> We are having the same problem, in the new version people have captured >>> random macs, and they redirect to a page with information on how to disable >>> random macs. Would that really be the best way to solve it? I don't know, I >>> just know that it generates complaints, tickets in our environment. If you >>> have any idea of how to work around this situation, please send it to me at >>> dan...@unifor.br, thank you in advance. >>> >>> >>> >>> >>> *Daniel Ricardo* >>> >>> Analista de Infraestrutura >>> NATI - Núcleo de Aplicação em Tecnologia da Informação >>> >>> Universidade de Fortaleza >>> >>> Tel.: (85) 3477.3302 >>> >>> >>> >>> Em qua., 11 de jan. de 2023 às 10:52, Ian MacDonald via >>> PacketFence-users <packetfence-users@lists.sourceforge.net> escreveu: >>> >>>> Hi Packetfence, >>>> >>>> We have been struggling with some newer model mobile devices with our >>>> WiFi captive portal implementation using Packetfence, and have not seen any >>>> change in the behavior on 11.0 thru 12.1 with our current connection >>>> profile. >>>> >>>> We do not use an inline configuration, and now we are upgraded to 12.1 >>>> on Debian 11, though we have not seen any related changelogs for specific >>>> device enumeration related to our issue, so we believe there is some new >>>> capabilities in how these platforms handle WiFi Login that we are missing >>>> configuration for. >>>> >>>> A bit more about our environment. >>>> >>>> Our switch groups are OpenWRT/hostapd based with CoA configured for >>>> Registration/Isolation/Management VLANs connected to our server, and a >>>> Default local VLAN for Internet access that varies depending on the switch >>>> location. >>>> >>>> Based on MAC, devices connect, and receive Internet access for a short >>>> period of time, before completing email-based activation to grant them a >>>> longer access window. >>>> >>>> All devices detect the WiFi login request on the registration network >>>> and prompt users for an email to complete authentication. When the email >>>> is sent, PF completes radius accounting, sets the device MAC as registered >>>> and issues a CoA to boot the device after a brief delay to account for >>>> hostapd delay in processing radius changes. It is at this point where >>>> the process fails for some devices. >>>> >>>> Samsung Galaxy S9 / S10 devices (Android 12) move through this step and >>>> are handed the default redirection page per their connection profile. >>>> >>>> Newer S22 and iPhone 14 devices are shown a Packetfence error occurred >>>> page, which shows the IP address of the gateway for the Default VLAN and >>>> MAC:0. So they made it to the Normal/Default VLAN and in packetfence they >>>> are registered. >>>> >>>> It seems that right after the CoA disconnect, when the device >>>> reconnects to the WiFi on the correct VLAN, it detects a sign-in >>>> requirement (Or simply retries the login page) and heads to the portal on >>>> the server which feeds it an error message. But is on the Default VLAN, >>>> so a smart user can cancel the Login and choose to "stay connected without >>>> Internet" and they are fine. >>>> >>>> Clearly the Internet detection is failing for the device, or it >>>> believes this due to cancelling a login process. >>>> >>>> Just reading this makes me think perhaps we are missing a setting >>>> defined for newer devices, as the config is pretty simple (from the command >>>> line anyway). I think it is time to try a default connection profile >>>> configured from scratch and see if it adds something we are missing. >>>> >>>> If anyone has experience with this issue, feel free to post back so we >>>> can shortcut our triage, and finally move on to upgrading our production >>>> systems from 11.0 and fixing these newer mobile devices. >>>> >>>> cheers, >>>> Ian >>>> >>>> Our profile in testing: >>>> [Lab] >>>> description=Captive Portal >>>> filter=ssid:PFTest_WiFi >>>> locale= >>>> redirecturl=https://someplace.com/ >>>> logo=/common/logo.png >>>> sources=email >>>> preregistration=disabled >>>> >>>> Our switch config has one setting I am not sure about, but otherwise >>>> has our VLANs, radius creds in it. >>>> always_trigger=1 >>>> >>>> Of pf.conf [Captive Portal] includes: >>>> wispr_redirection=enabled >>>> network_detection_ip=<The IP of a reachable Web Server> >>>> network_redirect_delay=25s >>>> >>>> _______________________________________________ >>>> PacketFence-users mailing list >>>> PacketFence-users@lists.sourceforge.net >>>> https://lists.sourceforge.net/lists/listinfo/packetfence-users >>>> >>> >>> Unifor.br <https://unifor.br/> | Instagram >>> <https://www.instagram.com/uniforcomunica/?hl=pt-br> | Facebook >>> <https://www.facebook.com/uniforoficial/> | Twitter >>> <https://twitter.com/UniforOficial> | LinkedIn >>> <https://www.linkedin.com/school/university-of-fortaleza/?originalSubdomain=pt> >>> | TV Unifor <https://www.unifor.br/tv-unifor> | G1/Ensinando e >>> Aprendendo >>> <https://g1.globo.com/ce/ceara/especial-publicitario/unifor/ensinando-e-aprendendo/> >>> ------------------------------ >>> >>> >>> <https://g1.globo.com/ce/ceara/especial-publicitario/unifor/ensinando-e-aprendendo/> >>> >> _______________________________________________ >> PacketFence-users mailing list >> PacketFence-users@lists.sourceforge.net >> https://lists.sourceforge.net/lists/listinfo/packetfence-users >> >
_______________________________________________ PacketFence-users mailing list PacketFence-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/packetfence-users