Issue with deleted nodes reprovisioning and provisioner failing to apply settings PF11.1.

[RHDHV-simon-sutcliffe]

Describe the bug We are not 100% what causes this to happen but here is some background in the hope you can reproduce the issue, or it may give you some clues as to the cause.

We have a DPSK connection profile that is tied to an SSID coming from a WLC. In that profile we added a provisioner.

Standard Connection Profile Settings enabled are Enable Profile = Enabled Root Portal Module = Default portal policy Enable DPSK = Enabled Default PSK Key = OurPSK Filters = any Filter 1 SSID OURSSID Sources 1 OurADSource Provisioners 1 STAFF-DPSK

In the Provisioner STAFF-DPSK we have the following TYPE = DPSK Enforced = Enabled Auto Register = Enabled Apply Role = Enabled Role to apply = Guest Roles = Users SSID = OurSSID

In the Authentication Sources OurADSource

Authentication Rules (Catchall) Role = Users Access Duration = 1 Day

WLC is configured with WebRedirect

To Reproduce Steps to reproduce the behavior:

1. Start with a unknown device to PF and run through the process.

a. Connect to OURSSID using the OurPSK b. Logon to AD c See new DPSK and mention of OURSSID

2. Goto Nodes

3. First issue we saw review the newly created node Role = User and Registered = unReg (We expected Role=Guest and Registered = Registered

4. Delete the node and also the user that created the node.

5. Go back through steps a and b

6. We see to error message displayed on devices (we are unsure when we see one or the other as we changed settings.

Caught exception in captiveportal::Controller::Root->dynamic_application "Can't use string ("0") as a HASH ref while "strict refs" in use at /usr/local/pf/lib/pf/provisioner/mobileconfig.pm line 342."

Caught exception in captiveportal::Controller::DeviceRegistration->registerNode "Can't use string ("0") as a HASH ref while "strict refs" in use at /usr/local/pf/lib/pf/security_event.pm line 641."

Pressing the swirl icon at the top gets rid of the message and it continues but the device is never correctly provisioned as per the requirements.

In the logging at the time we saw these errors too. Dec 15 18:01:33 packetfence packetfence_httpd.portal[83875]: httpd.portal(83875) ERROR: [mac:fc:d9:08:aa:09:95] 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 ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ? ) ON DUPLICATE KEY UPDATE category_id = ?, pid = ?, tenant_id = ?, unregdate = ?]{no, NULL, NULL, NULL, 1, NULL, 2021-12-15 18:00:11, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, 0000-00-00 00:00:00, 0000-00-00 00:00:00, 2021-12-15 18:01:33, 0000-00-00 00:00:00, fc:d9:08:aa:09:95, NULL, NULL, bob@testdomain.net, 0000-00-00 00:00:00, 0a07eff10000009e61ba1fbf, unreg, 1, NULL, 2021-12-16 17:38:11, NULL, no, 1, bob@testdomain.net, 1, 2021-12-16 17:38:11} (pf::dal::db_execute) Dec 15 18:01:33 packetfence packetfence_httpd.portal[83875]: httpd.portal(83875) ERROR: [mac:fc:d9:08:aa:09:95] Unable to modify node 'fc:d9:08:aa:09:95 (pf::node::node_modify) Dec 15 18:01:33 packetfence packetfence_httpd.portal[83875]: httpd.portal(83875) INFO: [mac:fc:d9:08:aa:09:95] Found provisioner Staff-DPSK for fc:d9:08:aa:09:95 (captiveportal::PacketFence::DynamicRouting::Module::Provisioning::execute_child) Dec 15 18:01:33 packetfence packetfence_httpd.portal[83875]: httpd.portal(83875) ERROR: [mac:fc:d9:08:aa:09:95] Caught exception in captiveportal::Controller::Root->dynamic_application "Can't use string ("0") as a HASH ref while "strict refs" in use at /usr/local/pf/lib/pf/provisioner/mobileconfig.pm line 342." (captiveportal::PacketFence::Controller::Root::end)

Expected behavior Device ends up being Registered and with a Role Guest

Smartphone (please complete the following information):

• Device: RedMI
• OS: Android 11
• Browser stock browser

If you need more information, please feel free to reach out.

[nqb]

Hello @RHDHV-simon-sutcliffe,

Could you try to replicate the issue with an unknown node (never seen by PacketFence before and never deleted) and post logs here after step 3 ?

[RHDHV-simon-sutcliffe]

@nqb sorry for the delay. We will reconfigure this back in the lab ASAP. Christmas holidays are on us so it might be in the new year but I will see if we can get it in 2021 for you.

[RHDHV-simon-sutcliffe]

@nqb, I have not been able to reproduce the error as before, but we are back to what was the original issue with the provisioner.

The provisioner takes no action to register the node. It hands out the DPSK password to the user but the node status is unregistered.

This is the only item in the logging about the provisioner.

Dec 21 15:41:08 packetfence packetfence_httpd.portal[343950]: httpd.portal(343950) INFO: [mac:1c:4d:70:eb:2f:12] Found provisioner Staff-DPSK for 1c:4d:70:eb:2f:12 (captiveportal::PacketFence::DynamicRouting::Module::Provisioning::execute_child) Dec 21 15:41:08 packetfence packetfence_httpd.portal[343950]: httpd.portal(343950) INFO: [mac:1c:4d:70:eb:2f:12] PSK key has been generated for user bob@example.com (pf::provisioner::mobileconfig::generate_dpsk)

[RHDHV-simon-sutcliffe]

@nqb did you get to the bottom of this problem with the provisioner not applying the role?

[nqb]

Hello @RHDHV-simon-sutcliffe,

I didn't find the time to test that. We will certainly be able to test your workflow during our test phase for 11.2 which should start next week.

[RHDHV-simon-sutcliffe]

@nqb After a little more testing I have found the following additional information.

The error after deletion appears to tied to the user account not so much only the node. If this is also deleted the error occurs. But the strange thing is given time (not sure how long but it is at least hours) the error self rectifies. This suggests a clean up action solves the problem or it is a cache that is not getting correctly cleared.

Hope that helps.