Error in IP Accouting and dhcp listener

[becchett]

Dear all,
I installed PF 14.1 in an Almalinux 8 and now I am using the ZEN version as a last attempt.

In both cases I made a very simple configuration; the most important details are as follows:

I have one network card, eth0 (management) with some vlans: registration, isolation, production etc;

I defined a Radius authentication backend, I configured a switch and a network profile.

This interface & network type is “dhcplistener” type because PF only performs authentication,
gateway (nat) and dhcp server functions are performed by another server (10.25.0.254).

With this setup I'd like to manage access to the wired network via 802.1x. The problem is,
while the client connects, PF is unable to read the IP Address assigned by the DHCP server.

This is a big problem that I have to solve, otherwise I can't follow up with this project.

If you have some time for me I'll send you the following information: The Packetfence configuration file, the active
dhcp processes, the configuration of the network cards, the tcpdump session with which you can see that the
server receives information via vlan 25 on DHCP sessions, and finally the packetfence.log file.

Thanks for your attention.

Enrico

1. pf.conf
   `# Copyright (C) Inverse inc.
   [general]

domain=XXXXXXXX
hostname=pfsrv
dhcpservers=127.0.0.1,10.25.0.254
timezone=Europe/Rome
[interface eth0]
mask=255.255.0.0
ip=10.0.0.34
type=management
[interface eth0.25]
mask=255.255.0.0
type=dhcp-listener,portal
ip=10.25.0.1
[interface eth0.28]
type=internal
enforcement=vlan
ip=10.28.0.1
mask=255.255.0.0
[interface eth0.29]
type=internal
enforcement=vlan
ip=10.29.0.1
mask=255.255.0.0
`

2. ps axf | grep -i dhcp

2136664 pts/0 S+ 0:00 \_ grep -i dhcp 1588 ? Ssl 33:16 /usr/local/pf/sbin/pfdhcp 3626 ? S 0:00 \_ pfqueue - Queue:pfdhcplistener_external 3632 ? S 0:00 \_ pfqueue - Queue:pfdhcplistener 3624 ? Ss 0:05 pfdhcplistener 3846 ? S 0:00 \_ pfdhcplistener - eth0.25 3847 ? S 0:00 \_ pfdhcplistener - eth0.28 3848 ? S 0:00 \_ pfdhcplistener - eth0.29 3849 ? S 0:07 \_ pfdhcplistener - eth0

3. tcpdump:

`link-type EN10MB (Ethernet), snapshot length 262144 bytes
15:27:26.576206 IP (tos 0x0, ttl 255, id 10108, offset 0, flags [none], proto UDP (17), length 328)
0.0.0.0.68 > 255.255.255.255.67: [udp sum ok] BOOTP/DHCP, Request from ac:87:a3:12:81:47, length 300, xid 0x9370cc2
c, secs 4, Flags [none] (0x0000)
Client-Ethernet-Address ac:87:a3:12:81:47
Vendor-rfc1048 Extensions
Magic Cookie 0x63825363
DHCP-Message (53), length 1: Request
Parameter-Request (55), length 12:
Subnet-Mask (1), Classless-Static-Route (121), Default-Gateway (3), Domain-Name-Server (6)
Domain-Name (15), Unknown (108), URL (114), Unknown (119)
Unknown (252), LDAP (95), Netbios-Name-Server (44), Netbios-Node (46)
MSZ (57), length 2: 1500
Client-ID (61), length 7: ether ac:87:a3:12:81:47
Requested-IP (50), length 4: 10.25.1.1
Lease-Time (51), length 4: 7776000
Hostname (12), length 12: "becchetti-nb"

1 packet captured
1 packet received by filter
0 packets dropped by kernel
`

4. profile.conf

[INFN-WIRED] description=INFN-WIRED locale= filter=connection_type:Ethernet-EAP sources=RADIUS-AAI autoregister=enabled advanced_filter=

5. packetfence.log

2025-03-24T09:58:57.792481+01:00 pfsrv pfqueue-backend[1643737]: pfqueue(2370) INFO: [mac:unknown] Running task api (main::process_data) 2025-03-24T09:58:57.793501+01:00 pfsrv pfqueue-backend[1643737]: pfqueue(2370) INFO: [mac:unknown] Calling api task fingerbank_process (pf::task::api::doTask) 2025-03-24T09:59:01.231313+01:00 pfsrv pfperl-api-docker-wrapper[1093706]: pfperl-api(17) INFO: [mac:[undef]] getting security_events triggers for accounting cleanup (pf::accounting::acct_maintenance) 2025-03-24T09:59:01.324585+01:00 pfsrv pfperl-api-docker-wrapper[1093706]: pfperl-api(15) INFO: [mac:[undef]] processed 0 security_events during security_event maintenance (1742806741.19886 1742806741.32022) (pf::security_event::security_event_maintenance) 2025-03-24T09:59:02.179011+01:00 pfsrv pfperl-api-docker-wrapper[1093706]: pfperl-api(15) INFO: [mac:[undef]] Using 300 resolution threshold (pf::pfcron::task::cluster_check::run) 2025-03-24T09:59:02.179527+01:00 pfsrv pfperl-api-docker-wrapper[1093706]: pfperl-api(15) INFO: [mac:[undef]] All cluster members are running the same configuration version (pf::pfcron::task::cluster_check::run) 2025-03-24T09:59:07.940572+01:00 pfsrv pfqueue-backend[1669088]: pfqueue(2370) INFO: [mac:unknown] Running task api (main::process_data) 2025-03-24T09:59:07.940572+01:00 pfsrv pfqueue-backend[1669088]: pfqueue(2370) INFO: [mac:unknown] Calling api task fingerbank_process (pf::task::api::doTask) 2025-03-24T09:59:18.129440+01:00 pfsrv pfqueue-backend[1636856]: pfqueue(2370) INFO: [mac:unknown] Running task api (main::process_data) 2025-03-24T09:59:18.129440+01:00 pfsrv pfqueue-backend[1636856]: pfqueue(2370) INFO: [mac:unknown] Calling api task fingerbank_process (pf::task::api::doTask) 2025-03-24T09:59:28.307902+01:00 pfsrv pfqueue-backend[1645264]: pfqueue(2370) INFO: [mac:unknown] Running task api (main::process_data) 2025-03-24T09:59:28.308633+01:00 pfsrv pfqueue-backend[1645264]: pfqueue(2370) INFO: [mac:unknown] Calling api task fingerbank_process (pf::task::api::doTask) 2025-03-24T09:59:35.953879+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] handling radius autz request: from switch_ip => (10.0.0.111), connection_type => Ethernet-EAP, switch_mac => (6c:c2:17:af:31:20), mac => [44:f0:9e:a9:e8:8e], port => 4, username => "[email protected]" (pf::radius::authorize) 2025-03-24T09:59:36.200823+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Instantiate profile INFN-WIRED (pf::Connection::ProfileFactory::_from_profile) 2025-03-24T09:59:36.321326+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Found authentication source(s) : 'RADIUS-AAI' for realm 'default' (pf::config::util::filter_authentication_sources) 2025-03-24T09:59:36.321326+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Using sources RADIUS-AAI for matching (pf::authentication::match2) 2025-03-24T09:59:36.321326+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Matched rule (catchall) in source RADIUS-AAI, returning actions. (pf::Authentication::Source::match_rule) 2025-03-24T09:59:36.321326+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Matched rule (catchall) in source RADIUS-AAI, returning actions. (pf::Authentication::Source::match) 2025-03-24T09:59:36.322117+01:00 pfsrv pfqueue-backend[1636856]: pfqueue(2370) INFO: [mac:unknown] Running task person_lookup (main::process_data) 2025-03-24T09:59:36.324875+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Found authentication source(s) : 'RADIUS-AAI' for realm 'default' (pf::config::util::filter_authentication_sources) 2025-03-24T09:59:36.324875+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Role has already been computed and we don't want to recompute it. Getting role from node_info (pf::role::getRegisteredRole) 2025-03-24T09:59:36.324875+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Username was defined "[email protected]" - returning role 'default' (pf::role::getRegisteredRole) 2025-03-24T09:59:36.326776+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] PID: "[email protected]", Status: reg Returned VLAN: (undefined), Role: default (pf::role::fetchRoleForNode) 2025-03-24T09:59:36.365777+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] (10.0.0.111) Added VLAN 25 to the returned RADIUS Access-Accept (pf::Switch::returnRadiusAccessAccept) 2025-03-24T09:59:36.380313+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] security_event 1300003 force-closed for 44:f0:9e:a9:e8:8e (pf::security_event::security_event_force_close) 2025-03-24T09:59:36.380313+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Instantiate profile INFN-WIRED (pf::Connection::ProfileFactory::_from_profile) 2025-03-24T09:59:36.463004+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Updating locationlog from accounting request (pf::api::handle_accounting_metadata) 2025-03-24T09:59:36.891759+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Database /usr/local/fingerbank/db/fingerbank_Local.db was changed or handles weren't initialized. Creating handle. (fingerbank::DB::SQLite::build_handle) 2025-03-24T09:59:37.082221+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Database /usr/local/fingerbank/db/fingerbank_Upstream.db was changed or handles weren't initialized. Creating handle. (fingerbank::DB::SQLite::build_handle) 2025-03-24T09:59:37.218456+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) WARN: [mac:44:f0:9e:a9:e8:8e] Cannot find any combination ID in any schemas (fingerbank::Source::LocalDB::_getCombinationID) 2025-03-24T09:59:37.219320+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Upstream is configured and unable to fullfil an exact match locally. Will ignore result from local database (fingerbank::Source::LocalDB::match) 2025-03-24T09:59:37.973862+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Successfully interrogate upstream Fingerbank project for matching. Got device : 33449 (fingerbank::Source::Collector::match) 2025-03-24T09:59:38.444384+01:00 pfsrv pfqueue-backend[1833161]: pfqueue(2370) INFO: [mac:unknown] Running task api (main::process_data) 2025-03-24T09:59:38.444384+01:00 pfsrv pfqueue-backend[1833161]: pfqueue(2370) INFO: [mac:unknown] Calling api task fingerbank_process (pf::task::api::doTask) 2025-03-24T09:59:41.660022+01:00 pfsrv pfqueue-backend[1648078]: pfqueue(2370) INFO: [mac:unknown] Running task api (main::process_data) 2025-03-24T09:59:41.660022+01:00 pfsrv pfqueue-backend[1648078]: pfqueue(2370) INFO: [mac:unknown] Calling api task process_dhcpv4 (pf::task::api::doTask) 2025-03-24T09:59:41.660022+01:00 pfsrv pfqueue-backend[1648078]: pfqueue(2370) INFO: [mac:unknown] DHCPREQUEST from 44:f0:9e:a9:e8:8e (10.25.128.33) (pf::dhcp::processor_v4::parse_dhcp_request) 2025-03-24T09:59:41.660022+01:00 pfsrv pfqueue-backend[1648078]: pfqueue(2370) INFO: [mac:unknown] The listener process is NOT on the same server as the DHCP server. (pf::dhcp::processor_v4::pf_is_dhcp) 2025-03-24T09:59:41.794642+01:00 pfsrv pfqueue-backend[1648078]: pfqueue(2370) ERROR: [mac:unknown] An error occured while sending a JSONRPC request: 35 SSL connect error gnutls_handshake() failed: The TLS connection was non-properly terminated. (pf::api::jsonrpcclient::notify) 2025-03-24T09:59:41.891895+01:00 pfsrv pfqueue-backend[1648078]: pfqueue(2370) ERROR: [mac:unknown] An error occured while sending a JSONRPC request: 35 SSL connect error gnutls_handshake() failed: The TLS connection was non-properly terminated. (pf::api::jsonrpcclient::notify) 2025-03-24T09:59:42.029943+01:00 pfsrv pfqueue-backend[1648078]: pfqueue(2370) ERROR: [mac:unknown] An error occured while sending a JSONRPC request: 35 SSL connect error gnutls_handshake() failed: The TLS connection was non-properly terminated. (pf::api::jsonrpcclient::notify) 2025-03-24T09:59:44.525775+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Searching for 'DHCP6_Enterprise' entries in schema(s) returned an empty set (fingerbank::Base::CRUD::search) 2025-03-24T09:59:44.533846+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) INFO: [mac:44:f0:9e:a9:e8:8e] Searching for 'DHCP6_Fingerprint' entries in schema(s) returned an empty set (fingerbank::Base::CRUD::search) 2025-03-24T09:59:44.598389+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) WARN: [mac:44:f0:9e:a9:e8:8e] Unable to pull accounting history for device 44:f0:9e:a9:e8:8e. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) 2025-03-24T09:59:44.839682+01:00 pfsrv httpd.aaa-docker-wrapper[2616]: httpd.aaa(7) WARN: [mac:44:f0:9e:a9:e8:8e] Unable to pull accounting history for device 44:f0:9e:a9:e8:8e. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) 2025-03-24T09:59:48.621187+01:00 pfsrv pfqueue-backend[1651522]: pfqueue(2370) INFO: [mac:unknown] Running task api (main::process_data) 2025-03-24T09:59:48.622365+01:00 pfsrv pfqueue-backend[1651522]: pfqueue(2370) INFO: [mac:unknown] Calling api task fingerbank_process (pf::task::api::doTask) 2025-03-24T09:59:55.278117+01:00 pfsrv packetfence[2138067]: -e(2138067) INFO: generating /usr/local/pf/var/conf/ssl-certificates.conf (pf::services::manager::httpd::generateCommonConfig) 2025-03-24T09:59:55.288474+01:00 pfsrv packetfence[2138067]: -e(2138067) INFO: generating /usr/local/pf/var/conf/captive-portal-common (pf::services::manager::httpd::generateCommonConfig) 2025-03-24T09:59:55.914133+01:00 pfsrv httpd.webservices-docker-wrapper[2138145]: Running with args --sig-proxy=true --rm --name=httpd.webservices --add-host=containers-gateway.internal:host-gateway -h pfsrv -v /var/lib/mysql:/var/lib/mysql -v /etc/sudoers:/etc/sudoers -v /etc/sudoers.d/:/etc/sudoers.d/ -v /usr/local/fingerbank/conf:/usr/local/fingerbank/conf -v /usr/local/fingerbank/db:/usr/local/fingerbank/db -v /usr/local/pf/var/run:/usr/local/pf/var/run -ePF_UID=996 -e PF_GID=995 -eFINGERBANK_UID=999 -e FINGERBANK_GID=996 -eIS_A_CLASSIC_PF_CONTAINER=yes -eTZ=Europe/Rome -p 9090:9090 -v/usr/local/pf/var/conf/:/usr/local/pf/var/conf/ -v/usr/local/pf/conf/:/usr/local/pf/conf/ -v/usr/local/pf/raddb/certs:/usr/local/pf/raddb/certs --privileged -v /run/systemd/system:/run/systemd/system -v /var/run/dbus/system_bus_socket:/var/run/dbus/system_bus_socket -v/usr/local/pf/html/captive-portal/profile-templates:/usr/local/pf/html/captive-portal/profile-templates 2025-03-24T09:59:55.985457+01:00 pfsrv httpd.webservices-docker-wrapper[2138167]: docker: Error response from daemon: Conflict. The container name "/httpd.webservices" is already in use by container "0d1230528195386e6ec4acc4bc2ba6e853d17ce6fd4612058a2c35a75e8ba5f9". You have to remove (or rename) that container to be able to reuse that name. 2025-03-24T09:59:58.769884+01:00 pfsrv pfqueue-backend[1648078]: pfqueue(2370) INFO: [mac:unknown] Running task api (main::process_data) 2025-03-24T09:59:58.770547+01:00 pfsrv pfqueue-backend[1648078]: pfqueue(2370) INFO: [mac:unknown] Calling api task fingerbank_process (pf::task::api::doTask) 2025-03-24T10:00:01.304336+01:00 pfsrv packetfence[2138201]: -e(2138201) INFO: generating /usr/local/pf/var/conf/ssl-certificates.conf (pf::services::manager::httpd::generateCommonConfig) 2025-03-24T10:00:01.321864+01:00 pfsrv packetfence[2138201]: -e(2138201) INFO: generating /usr/local/pf/var/conf/captive-portal-common (pf::services::manager::httpd::generateCommonConfig) 2025-03-24T10:00:01.379366+01:00 pfsrv pfperl-api-docker-wrapper[1093706]: pfperl-api(17) INFO: [mac:[undef]] Using 300 resolution threshold (pf::pfcron::task::cluster_check::run) 2025-03-24T10:00:01.379366+01:00 pfsrv pfperl-api-docker-wrapper[1093706]: pfperl-api(17) INFO: [mac:[undef]] All cluster members are running the same configuration version (pf::pfcron::task::cluster_check::run) 2025-03-24T10:00:01.568863+01:00 pfsrv httpd.webservices-docker-wrapper[2138276]: Running with args --sig-proxy=true --rm --name=httpd.webservices --add-host=containers-gateway.internal:host-gateway -h pfsrv -v /var/lib/mysql:/var/lib/mysql -v /etc/sudoers:/etc/sudoers -v /etc/sudoers.d/:/etc/sudoers.d/ -v /usr/local/fingerbank/conf:/usr/local/fingerbank/conf -v /usr/local/fingerbank/db:/usr/local/fingerbank/db -v /usr/local/pf/var/run:/usr/local/pf/var/run -ePF_UID=996 -e PF_GID=995 -eFINGERBANK_UID=999 -e FINGERBANK_GID=996 -eIS_A_CLASSIC_PF_CONTAINER=yes -eTZ=Europe/Rome -p 9090:9090 -v/usr/local/pf/var/conf/:/usr/local/pf/var/conf/ -v/usr/local/pf/conf/:/usr/local/pf/conf/ -v/usr/local/pf/raddb/certs:/usr/local/pf/raddb/certs --privileged -v /run/systemd/system:/run/systemd/system -v /var/run/dbus/system_bus_socket:/var/run/dbus/system_bus_socket -v/usr/local/pf/html/captive-portal/profile-templates:/usr/local/pf/html/captive-portal/profile-templates 2025-03-24T10:00:01.605333+01:00 pfsrv httpd.webservices-docker-wrapper[2138287]: Error response from daemon: No such container: httpd.webservices 2025-03-24T10:00:02.302720+01:00 pfsrv pfperl-api-docker-wrapper[1093706]: pfperl-api(17) INFO: [mac:[undef]] getting security_events triggers for accounting cleanup (pf::accounting::acct_maintenance) 2025-03-24T10:00:02.413454+01:00 pfsrv pfperl-api-docker-wrapper[1093706]: pfperl-api(17) INFO: [mac:[undef]] processed 0 security_events during security_event maintenance (1742806802.26966 1742806802.39827) (pf::security_event::security_event_maintenance)