0001655: Inline Mode not forwarding after registration - PacketFence

(0003330)
rivan (reporter)
2013-06-26 05:06

I'm experiencing the same problem.
try to reboot the registered node.
but of course this is not a permanent solution.

(0003331)
JasonFell (reporter)
2013-07-02 06:15

Forgot to add a couple of details:
Centos 6.4 minimal install.
clients tested with the same fault;
Win7
WinXP
Android 4.1.2

can you also let me know when there might be some movement on this issue?

(0003332)
rivan (reporter)
2013-07-02 22:28
edited on: 2013-07-02 22:29

did you remove the secure redirect?

(0003333)
JasonFell (reporter)
2013-07-03 04:31

Hi Rivan,
Removed the secure redirect, but still no joy.
Why would this make a difference to the forwarding of packets?
it seems more likely that the method for allowing access through packetfence does not update correctly (if I restart the services I get access)

(0003334)
rivan (reporter)
2013-07-04 23:01
edited on: 2013-07-04 23:01

you have to restart the services after you reboot packetfence. It's a bug.

(0003335)
JasonFell (reporter)
2013-07-09 05:47
edited on: 2013-07-15 07:26

That seemed like a silly run-a-round.
I have just re-installed pf and found that the secure redirect did not help me at all.
I still cannot get access from a workstation (or any other device) to the internet unless I restart the pf services (after the user has registered)! This is a major stumbling block as this would stop others from using the internet for the 60-120 seconds that the service is unavailable.....for every person who wants to register!!

(0003342)
JasonFell (reporter)
2013-07-18 03:48

After waiting for some help with fixing this bug I can now inform you that I have made some progress, but it seems that the 'inline' functionality does not work the same as 'out-of-band' enforcement.
I made a leap of faith and installed both type of enforcement, even though I did not require both, and then 'created' 2 further (un-required) interfaces within the configurator for the 2 vlans (isolation & registration). I then proceeded to test further and found that all is working as it should be without issue.
I have taken a note of the packetfence.log file and will attached to this bug report.

on a side note I do find it amazing that the product is purported to support 'inline' enforcement (without implementing features that are not required), but it seems from my initial findings that this is not the case, and the support, or even advice, as been almost non-existent.

(0003360)
fdurand (administrator)
2013-07-31 20:13

Hello,
is the captive portal you hit is on a inline interface ?
Can you paste me the result of ipset -L ?

Regards
Fabrice

(0003362)
jvlien (reporter)
2013-08-01 03:39

Dear All,

I experience the same issue.
I have not tested rebooting the server but the client as suggested in the pf message to the client.

The ipsec -L before rebooting the client (IP 192.168.64.92 - MAC: 00:50:56:B5:8B:33):
Name: pfsession_Reg_192.168.64.0
Type: bitmap:ip,mac
Header: range 192.168.64.0-192.168.64.255
Size in memory: 4208
References: 1
Members:
192.168.64.83,54:26:96:A0:B9:F7
192.168.64.89,B8:F6:B1:AC:1B:56

The ipsec -L after rebooting the client (IP 192.168.64.92 - MAC: 00:50:56:B5:8B:33):
Name: pfsession_Reg_192.168.64.0
Type: bitmap:ip,mac
Header: range 192.168.64.0-192.168.64.255
Size in memory: 4208
References: 1
Members:
192.168.64.83,54:26:96:A0:B9:F7
192.168.64.89,B8:F6:B1:AC:1B:56
192.168.64.92,00:50:56:B5:8B:33

Before rebooting the client, packetfence.log shows:
Aug 01 10:25:03 redir.cgi(0) ERROR: Error while setting locale to en_US.utf8. (pf::Portal::Session::_initializeI18n)
Aug 01 10:25:03 redir.cgi(0) INFO: 00:50:56:b5:8b:33 being redirected (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_redir_2ecgi::handler)
Aug 01 10:25:03 redir.cgi(0) INFO: Updating node 00:50:56:b5:8b:33 user_agent with useragent: 'Mozilla/5.0 (Windows NT 5.1; rv:22.0) Gecko/20100101 Firefox/22.0' (pf::web::web_node_record_user_agent)
Aug 01 10:25:03 redir.cgi(0) INFO: Static User-Agent lookup data initialized (pf::useragent::_init)
Aug 01 10:25:03 redir.cgi(0) INFO: MAC 00:50:56:b5:8b:33 shouldn't reach here. Calling access re-evaluation. Make sure your network device configuration is correct. (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_redir_2ecgi::handler)
Aug 01 10:25:03 redir.cgi(0) INFO: re-evaluating access for node 00:50:56:b5:8b:33 (redir.cgi called) (pf::enforcement::reevaluate_access)
Aug 01 10:25:03 redir.cgi(0) INFO: Instantiate a new iptables modification method. pf::ipset (pf::inline::get_technique)

After rebooting the client:
ug 01 10:28:08 pfdhcplistener(3356) INFO: DHCPREQUEST from 00:50:56:b5:8b:33 (192.168.64.92) (main::parse_dhcp_request)
Aug 01 10:28:08 pfdhcplistener(3356) INFO: MAC: 00:50:56:b5:8b:33 stated changed, adapting firewall rules for proper enforcement (pf::inline::performInlineEnforcement)
Aug 01 10:28:08 pfdhcplistener(3356) INFO: 00:50:56:b5:8b:33 requested an IP. DHCP Fingerprint: OS::100 (Microsoft Windows XP). Modified node with last_dhcp = 2013-08-01 10:28:08,computername = pos03,dhcp_fingerprint = 1,15,3,6,44,46,47,31,33,249,43 (main::listen_dhcp)
Aug 01 10:28:08 pfdhcplistener(3356) INFO: DHCPACK from 192.168.64.5 (00:50:56:b5:9b:ba) to host 00:50:56:b5:8b:33 (192.168.64.92) for 86400 seconds (main::parse_dhcp_ack)

Note:
192.168.64.5 is the pf server Inline interface IP.

(0003365)
fdurand (administrator)
2013-08-01 08:12

Ok so ipset is working, is ip_forward enabled ?
Can you paste the iptables -L -n -v and iptables -L -n -v -t nat ?

Fabrice

(0003367)
jvlien (reporter)
2013-08-01 08:40

#iptables -L -n -v
Chain INPUT (policy DROP 8842 packets, 866K bytes)
pkts bytes target prot opt in out source destination
  587 1313K ACCEPT all -- lo * 0.0.0.0/0 0.0.0.0/0
53092 70M ACCEPT all -- * * 0.0.0.0/0 0.0.0.0/0 state RELATED,ESTABLISHED
    0 0 ACCEPT icmp -- * * 0.0.0.0/0 0.0.0.0/0 icmptype 8
1620 79639 input-internal-inline-if all -- eth2 * 0.0.0.0/0 192.168.64.5
  605 175K input-internal-inline-if all -- eth2 * 0.0.0.0/0 255.255.255.255
    0 0 ACCEPT tcp -- eth2 * 0.0.0.0/0 192.168.65.211 tcp dpt:443
    9 476 input-management-if all -- eth1 * 0.0.0.0/0 0.0.0.0/0
    5 260 ACCEPT tcp -- eth0 * 0.0.0.0/0 0.0.0.0/0 tcp dpt:22

Chain FORWARD (policy DROP 1593 packets, 88109 bytes)
pkts bytes target prot opt in out source destination
2370 166K forward-internal-inline-if all -- eth2 * 0.0.0.0/0 0.0.0.0/0
  639 317K ACCEPT all -- eth1 * 0.0.0.0/0 0.0.0.0/0 state RELATED,ESTABLISHED

Chain OUTPUT (policy ACCEPT 35265 packets, 7414K bytes)
pkts bytes target prot opt in out source destination

Chain forward-internal-inline-if (1 references)
pkts bytes target prot opt in out source destination
    0 0 ACCEPT all -- * * 0.0.0.0/0 0.0.0.0/0 mark match 0x3 match-set pfsession_passthrough dst,dst
  777 77790 ACCEPT all -- * * 0.0.0.0/0 0.0.0.0/0 mark match 0x1

Chain forward-internal-vlan-if (0 references)
pkts bytes target prot opt in out source destination
    0 0 ACCEPT all -- * * 0.0.0.0/0 0.0.0.0/0 match-set pfsession_passthrough dst,dst
    0 0 ACCEPT all -- * * 0.0.0.0/0 0.0.0.0/0 match-set pfsession_passthrough src,src

Chain input-highavailability-if (0 references)
pkts bytes target prot opt in out source destination
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 state NEW tcp dpt:22
    0 0 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:5405
    0 0 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:5407
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:7788

Chain input-internal-inline-if (2 references)
pkts bytes target prot opt in out source destination
    5 1717 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:67
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:67
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:53 mark match 0x3
  146 8491 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:53 mark match 0x3
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:53 mark match 0x2
    0 0 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:53 mark match 0x2
    0 0 DROP tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:53 mark match 0x1
    0 0 DROP udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:53 mark match 0x1
    3 144 DROP tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:80 mark match 0x1
    0 0 DROP tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:443 mark match 0x1
   19 912 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:80
   19 896 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:443

Chain input-internal-vlan-if (0 references)
pkts bytes target prot opt in out source destination
    0 0 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:53
    0 0 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:67
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:67
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:80
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:443

Chain input-management-if (1 references)
pkts bytes target prot opt in out source destination
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 state NEW tcp dpt:22
    8 420 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:1443
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:9090
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:1812
    0 0 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:1812
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:1813
    0 0 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:1813
    0 0 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:162
    0 0 ACCEPT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:67
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:67
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:9392
    0 0 ACCEPT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:8834

# iptables -L -n -v -t nat
Chain PREROUTING (policy ACCEPT 11776 packets, 1115K bytes)
pkts bytes target prot opt in out source destination
4767 457K prerouting-int-inline-if all -- eth2 * 0.0.0.0/0 0.0.0.0/0

Chain INPUT (policy ACCEPT 196 packets, 12121 bytes)
pkts bytes target prot opt in out source destination

Chain OUTPUT (policy ACCEPT 90 packets, 5600 bytes)
pkts bytes target prot opt in out source destination

Chain POSTROUTING (policy ACCEPT 113 packets, 8001 bytes)
pkts bytes target prot opt in out source destination
  142 9836 MASQUERADE all -- * eth1 0.0.0.0/0 0.0.0.0/0
    0 0 postrouting-int-inline-if all -- * eth1 0.0.0.0/0 0.0.0.0/0 mark match 0x3
    0 0 postrouting-int-inline-if all -- * eth1 0.0.0.0/0 0.0.0.0/0 mark match 0x1
    0 0 postrouting-int-inline-if all -- * eth1 0.0.0.0/0 0.0.0.0/0 mark match 0x2

Chain postrouting-inline-routed (0 references)
pkts bytes target prot opt in out source destination
    0 0 ACCEPT all -- * * 0.0.0.0/0 0.0.0.0/0

Chain postrouting-int-inline-if (3 references)
pkts bytes target prot opt in out source destination
    0 0 MASQUERADE all -- * * 0.0.0.0/0 0.0.0.0/0

Chain prerouting-int-inline-if (1 references)
pkts bytes target prot opt in out source destination
  146 8479 REDIRECT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:53 mark match 0x3
    0 0 REDIRECT udp -- * * 0.0.0.0/0 0.0.0.0/0 udp dpt:53 mark match 0x2
    0 0 ACCEPT all -- * * 0.0.0.0/0 0.0.0.0/0 match-set pfsession_passthrough dst,dst mark match 0x3
   19 912 REDIRECT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:80 mark match 0x3
    0 0 REDIRECT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:80 mark match 0x2
   17 816 REDIRECT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:443 mark match 0x3
    0 0 REDIRECT tcp -- * * 0.0.0.0/0 0.0.0.0/0 tcp dpt:443 mark match 0x2

#ifconfig
eth0 Link encap:Ethernet HWaddr 00:50:56:b5:b6:e0
          inet addr:192.168.60.13 Bcast:192.168.60.255 Mask:255.255.255.0
          inet6 addr: fe80::250:56ff:feb5:b6e0/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
          RX packets:63498 errors:0 dropped:0 overruns:0 frame:0
          TX packets:3566 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:4206524 (4.0 MiB) TX bytes:4622467 (4.4 MiB)

eth1 Link encap:Ethernet HWaddr 00:50:56:b5:3a:4c <--
          inet addr:192.168.65.211 Bcast:192.168.65.255 Mask:255.255.255.0
          inet6 addr: fe80::250:56ff:feb5:3a4c/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
          RX packets:49955 errors:0 dropped:0 overruns:0 frame:0
          TX packets:34783 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:70775434 (67.4 MiB) TX bytes:3166477 (3.0 MiB)

eth2 Link encap:Ethernet HWaddr 00:50:56:b5:9b:ba
          inet addr:192.168.64.5 Bcast:192.168.64.255 Mask:255.255.255.0
          inet6 addr: fe80::250:56ff:feb5:9bba/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
          RX packets:6999 errors:0 dropped:0 overruns:0 frame:0
          TX packets:2347 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:756693 (738.9 KiB) TX bytes:749056 (731.5 KiB)

lo Link encap:Local Loopback
          inet addr:127.0.0.1 Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING MTU:16436 Metric:1
          RX packets:871 errors:0 dropped:0 overruns:0 frame:0
          TX packets:871 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:2183212 (2.0 MiB) TX bytes:2183212 (2.0 MiB)

Interfaces:
* eth0 - Type: (None) - Comment: Interface on other LAN to allow remote access for management (I have added -A INPUT -i eth0 -p tcp --dport 22 -j ACCEPT in iptables.conf for this one)
* eth1 - Type: Management
- eth2 - Type: Inline

(0003368)
jvlien (reporter)
2013-08-01 08:41
edited on: 2013-08-01 10:04

Note: no need to reboot the client computer after all. On Windows an "ipconfig /renew" does the trick. For Wifi a disconnect then reconnect from the Wi-Fi network also works (Access Point directly connected to Inline net)

(0003369)
fdurand (administrator)
2013-08-01 09:14

And the iptables -L -n -v -t mangle too.

(0003370)
jvlien (reporter)
2013-08-01 10:03

# iptables -L -n -v -t mangle
Chain PREROUTING (policy ACCEPT 18149 packets, 4722K bytes)
pkts bytes target prot opt in out source destination
9936 993K prerouting-int-inline-if all -- eth2 * 0.0.0.0/0 0.0.0.0/0

Chain INPUT (policy ACCEPT 9734 packets, 2183K bytes)
pkts bytes target prot opt in out source destination

Chain FORWARD (policy ACCEPT 7840 packets, 2440K bytes)
pkts bytes target prot opt in out source destination

Chain OUTPUT (policy ACCEPT 3694 packets, 3250K bytes)
pkts bytes target prot opt in out source destination

Chain POSTROUTING (policy ACCEPT 10479 packets, 5632K bytes)
pkts bytes target prot opt in out source destination

Chain prerouting-int-inline-if (1 references)
pkts bytes target prot opt in out source destination
9936 993K MARK all -- * * 0.0.0.0/0 0.0.0.0/0 MARK set 0x3
0 0 MARK all -- * * 0.0.0.0/0 0.0.0.0/0 match-set pfsession_Unreg_192.168.64.0 src,src MARK set 0x3
3959 415K MARK all -- * * 0.0.0.0/0 0.0.0.0/0 match-set pfsession_Reg_192.168.64.0 src,src MARK set 0x1
0 0 MARK all -- * * 0.0.0.0/0 0.0.0.0/0 match-set pfsession_Isol_192.168.64.0 src,src MARK set 0x2

(0003371)
fdurand (administrator)
2013-08-01 15:40

Hum it look good because : 3959 415K MARK all -- * * 0.0.0.0/0 0.0.0.0/0 match-set pfsession_Reg_192.168.64.0 src,src MARK set 0x1

have you checked /proc/sys/net/ipv4/ip_forward is equal to 1 ?

Fabrice

(0003374)
jvlien (reporter)
2013-08-02 02:57

Yes, and once ipset -L shows the MAC/IP in the list the computer has access so it can't be this:
# cat /proc/sys/net/ipv4/ip_forward
1

It looks like something is not set when the client is logged in (auth is done via AD) and this same something is then triggered with the DHCP refresh:
Aug 01 10:28:08 pfdhcplistener(3356) INFO: MAC: 00:50:56:b5:8b:33 stated changed, adapting firewall rules for proper enforcement (pf::inline::performInlineEnforcement)

Would there be a way to trigger this event on the pf server to test if this is what is missing after login in but defore dhcp refresh?

(0003377)
fdurand (administrator)
2013-08-02 09:31

Your setup look good, can you paste the routing table ?

Fabrice

(0003378)
jvlien (reporter)
2013-08-02 09:41

# route
Kernel IP routing table
Destination Gateway Genmask Flags Metric Ref Use Iface
default 192.168.65.210 0.0.0.0 UG 0 0 0 eth1
192.168.60.0 * 255.255.255.0 U 0 0 0 eth0
192.168.64.0 * 255.255.255.0 U 0 0 0 eth2
192.168.65.0 * 255.255.255.0 U 0 0 0 eth1

(0003384)
fdurand (administrator)
2013-08-05 11:16

Your configuration looks correct, are you able to ping 192.168.65.210 from your device when your device is reg ?

(0003385)
jvlien (reporter)
2013-08-05 13:05

When the computer is in the pfsession_Reg_192.168.64.0, yes I can ping 192.168.65.210.

As I said when I reboot/renew DHCPlease/disconnect & reconnect to Wireless network it shows this in the log:
Aug 01 10:28:08 pfdhcplistener(3356) INFO: DHCPREQUEST from 00:50:56:b5:8b:33 (192.168.64.92) (main::parse_dhcp_request)
Aug 01 10:28:08 pfdhcplistener(3356) INFO: MAC: 00:50:56:b5:8b:33 stated changed, adapting firewall rules for proper enforcement (pf::inline::performInlineEnforcement)

And this seems to trigger the event that makes the computer to go from the pfsession_UnReg_192.168.64.0 to the pfsession_Reg_192.168.64.0 list but until this DHCPREQUEST the client stays in the Unreg list.

(0003386)
fdurand (administrator)
2013-08-05 13:56

Ok so try this:
su - pf
and launch sudo ipset -L
If it doesn´t work it mean that there is a problem with sudoers file.

(0003387)
jvlien (reporter)
2013-08-06 03:11

It looks like you're right!

# su - pf
$ /usr/sbin/ipset -L
ipset v6.12.1: Kernel error received: Operation not permitted

I have looked at the doc and unless I am mistaken I have not seen how to setup sudo (it is taken care of by the installation script?).

(0003434)
dranix (reporter)
2013-09-03 05:20

I am having the same issue highlighted by JasonFell.
So after reading this bug, i realize that the issue revolves around ipset.

My setup is as follows:
-CentOS 6.4
-PacketFence 4.0.5-2

A "discovery" of the bug:
Scenario when new user authenticates:
1. When a new user successfully authenticates and registers, the wireless device would be stuck at the webpage that states, "Your network should be enabled within a minute or two. If it is not reboot your computer.".
2. The wireless client will never be able to access the Internet even though in the PacketFence portal, the device is registered correctly.
3. Upon checking the ipset, this device is not reflected in the pfsession_Reg_x.x.x.x ipset.
4. After performing "service packetfence restart", then only will the client be able to access the Internet.
5. Upon checking the ipset now, the device's IP and MAC is present in the pfsession_Reg_x.x.x.x ipset.

Scenario when a node is deregistered and deleted.
1. When a node is successfully registered it is able to access the Internet.
2. In the PacketFence portal, when the node is deregistered and removed, the node is still present in the pfsession_Reg_x.x.x.x ipset.
3. This means that a "non-registered" device would still be able to access the Internet.
4. After performing "service packetfence restart", then only will the client not be able to access the Internet.
5. Upon checking the ipset now, the device's IP and MAC is not in the pfsession_Reg_x.x.x.x ipset.

To add on the jvlien observation.
Executing "ipset -L" from user pf would give the Kernel error.
But executing the command "sudo ipset -L" works fine.

So it has something to do with ipset not being executed by the pf user when wireless clients are added or removed.

Hope this information helps.
Thanks.

(0003442)
dranix (reporter)
2013-09-11 23:14

Updates to this bug.
Have tested with PacketFence 4.0.6.
Same problem still exists.
Newly registered wireless clients would not be able to access the Internet until PacketFence is restarted which "renews" the ipset list.
Thanks.

(0003451)
dranix (reporter)
2013-09-17 02:57

Updates to this bug
Have updated to PacketFence 4.0.6-2.
Same problem still exists.

Have included the logs from packetfence.log.
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

##New Registration with bad password
Sep 17 14:33:46 register.cgi(0) INFO: 172.31.200.10 - aa:bb:cc:dd:ee:ff on registration page (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_register_2ecgi::handler)
Sep 17 14:33:51 register.cgi(0) WARN: User cannot cn=test-staff,ou=people,dc=company,dc=com cannot bind from dc=company,dc=com on ldap-master.company.com:389 for source Staff (pf::Authentication::Source::LDAPSource::authenticate)
Sep 17 14:33:56 register.cgi(0) WARN: No entries found (0) with filter (cn=test-staff) from dc=intern,dc=company,dc=com on intern.company.com:389 for source Intern (pf::Authentication::Source::LDAPSource::authenticate)
##New Registration with good password
Sep 17 14:34:25 register.cgi(0) INFO: 172.31.200.10 - aa:bb:cc:dd:ee:ff on registration page (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_register_2ecgi::handler)
Sep 17 14:34:30 register.cgi(0) INFO: Authentication successful for test-staff in source Staff (LDAP) (pf::authentication::authenticate)
Sep 17 14:34:35 register.cgi(0) INFO: Found a match (cn=test-staff,ou=people,dc=company,dc=com) (pf::Authentication::Source::LDAPSource::match_in_subclass)
Sep 17 14:34:35 register.cgi(0) INFO: Matched rule (Staff) in source Staff, returning actions. (pf::Authentication::Source::match)
Sep 17 14:34:41 register.cgi(0) INFO: Found a match (cn=test-staff,ou=people,dc=company,dc=com) (pf::Authentication::Source::LDAPSource::match_in_subclass)
Sep 17 14:34:41 register.cgi(0) INFO: Matched rule (Staff) in source Staff, returning actions. (pf::Authentication::Source::match)
Sep 17 14:34:46 register.cgi(0) INFO: Found a match (cn=test-staff,ou=people,dc=company,dc=com) (pf::Authentication::Source::LDAPSource::match_in_subclass)
Sep 17 14:34:46 register.cgi(0) INFO: Matched rule (Staff) in source Staff, returning actions. (pf::Authentication::Source::match)
Sep 17 14:34:46 register.cgi(0) INFO: performing node registration MAC: aa:bb:cc:dd:ee:ff pid: test-staff (pf::web::_sanitize_and_register)
Sep 17 14:34:46 register.cgi(0) INFO: creating person test-staff because it doesn't exist (pf::node::node_register)
Sep 17 14:34:46 register.cgi(0) INFO: person test-staff added (pf::person::person_add)
Sep 17 14:34:46 register.cgi(0) INFO: re-evaluating access for node aa:bb:cc:dd:ee:ff (manage_register called) (pf::enforcement::reevaluate_access)
Sep 17 14:34:46 register.cgi(0) WARN: Can't re-evaluate access for mac aa:bb:cc:dd:ee:ff because no open locationlog entry was found (pf::enforcement::reevaluate_access)
Sep 17 14:34:55 redir.cgi(0) INFO: aa:bb:cc:dd:ee:ff being redirected (default profile) (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_redir_2ecgi::handler)
Sep 17 14:34:55 redir.cgi(0) INFO: MAC aa:bb:cc:dd:ee:ff shouldn't reach here. Calling access re-evaluation. Make sure your network device configuration is correct. (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_redir_2ecgi::handler)
Sep 17 14:34:55 redir.cgi(0) INFO: re-evaluating access for node aa:bb:cc:dd:ee:ff (redir.cgi called) (pf::enforcement::reevaluate_access)
Sep 17 14:34:55 redir.cgi(0) WARN: Can't re-evaluate access for mac aa:bb:cc:dd:ee:ff because no open locationlog entry was found (pf::enforcement::reevaluate_access)
##Unable to access after rebooting wireless client
Sep 17 14:35:44 redir.cgi(0) INFO: aa:bb:cc:dd:ee:ff being redirected (default profile) (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_redir_2ecgi::handler)
Sep 17 14:35:44 redir.cgi(0) INFO: MAC aa:bb:cc:dd:ee:ff shouldn't reach here. Calling access re-evaluation. Make sure your network device configuration is correct. (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_redir_2ecgi::handler)
Sep 17 14:35:44 redir.cgi(0) INFO: re-evaluating access for node aa:bb:cc:dd:ee:ff (redir.cgi called) (pf::enforcement::reevaluate_access)
Sep 17 14:35:44 redir.cgi(0) WARN: Can't re-evaluate access for mac aa:bb:cc:dd:ee:ff because no open locationlog entry was found (pf::enforcement::reevaluate_access)
Sep 17 14:35:51 redir.cgi(0) INFO: aa:bb:cc:dd:ee:ff being redirected (default profile) (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_redir_2ecgi::handler)
Sep 17 14:35:51 redir.cgi(0) INFO: MAC aa:bb:cc:dd:ee:ff shouldn't reach here. Calling access re-evaluation. Make sure your network device configuration is correct. (ModPerl::ROOT::ModPerl::PerlRun::usr_local_pf_html_captive_2dportal_redir_2ecgi::handler)
Sep 17 14:35:51 redir.cgi(0) INFO: re-evaluating access for node aa:bb:cc:dd:ee:ff (redir.cgi called) (pf::enforcement::reevaluate_access)
Sep 17 14:35:51 redir.cgi(0) WARN: Can't re-evaluate access for mac aa:bb:cc:dd:ee:ff because no open locationlog entry was found (pf::enforcement::reevaluate_access)

##check ipset before restarting packetfence
[root@packetfence logs]# ipset -L
Name: pfsession_Unreg_172.31.200.0
Type: bitmap:ip,mac
Header: range 172.31.200.0-172.31.203.255
Size in memory: 16496
References: 1
Members:

Name: pfsession_Reg_172.31.200.0
Type: bitmap:ip,mac
Header: range 172.31.200.0-172.31.203.255
Size in memory: 16496
References: 1
Members:

Name: pfsession_Isol_172.31.200.0
Type: bitmap:ip,mac
Header: range 172.31.200.0-172.31.203.255
Size in memory: 16496
References: 1
Members:

##Executed packetfence restart
service packetfence restart

##check ipset after restarting packetfence
[root@packetfence logs]# ipset -L
Name: pfsession_Unreg_172.31.200.0
Type: bitmap:ip,mac
Header: range 172.31.200.0-172.31.203.255
Size in memory: 16496
References: 1
Members:

Name: pfsession_Reg_172.31.200.0
Type: bitmap:ip,mac
Header: range 172.31.200.0-172.31.203.255
Size in memory: 16496
References: 1
Members:
172.31.200.10,aa:bb:cc:dd:ee:ff

Name: pfsession_Isol_172.31.200.0
Type: bitmap:ip,mac
Header: range 172.31.200.0-172.31.203.255
Size in memory: 16496
References: 1
Members:

##wireless client can surf the Internet without any issues

Hope the added information helps in the bug resolution.
Thanks.

(0003479)
showy (reporter)
2013-12-08 03:30

Hi,
I'm new to packetfence and I've just ran into this problem with a minimal installation of debian wheezy. Have installed packetfence 4.0.6-2 via aptitude and configured for inline mode.

A quick fix of the problem is to replace in the reevaluate_access function of the enforcement.pm file the block after the call to isInlineEnforcementRequired:

if ($inline->isInlineEnforcementRequired($mac)) {

                # TODO avoidable load?
                my $trapSender = pf::SwitchFactory->getInstance()->instantiate('127.0.0.1');
                if ($trapSender) {
                    $logger->debug("sending a local firewallRequest trap to force firewall change");
                    $trapSender->sendLocalFirewallRequestTrap('127.0.0.1', $mac);
                } else {


TO:

if ($inline->isInlineEnforcementRequired($mac)) {

$inline->performInlineEnforcement($mac);

} else {

PATCH <<

diff --git a/lib/pf/enforcement.pm b/lib/pf/enforcement.pm
index ebd975f..4cb863c 100644
--- a/lib/pf/enforcement.pm
+++ b/lib/pf/enforcement.pm
@@ -82,14 +82,7 @@ sub reevaluate_access {
             my $inline = new pf::inline::custom();
             if ($inline->isInlineEnforcementRequired($mac)) {

- # TODO avoidable load?
- my $trapSender = pf::SwitchFactory->getInstance()->instantiate('127.0.0.1');
- if ($trapSender) {
- $logger->debug("sending a local firewallRequest trap to force firewall change");
- $trapSender->sendLocalFirewallRequestTrap('127.0.0.1', $mac);
- } else {
- $logger->error("Can't instantiate switch 127.0.0.1! It's critical for internal messages!");
- }
+ $inline->performInlineEnforcement($mac);

             } else {
                 $logger->debug("MAC: $mac is already properly enforced in firewall, no change required");

(0003580)
jvlien (reporter)
2014-09-11 04:29

Dear All,

It's been a while but I had the same issue again recently and finally found out that the issue was due to lack of RAM. The pfsetvlan service took all the available RAM leaving no free memory for all the other services. pfdhcplistener would not start and ipset would throw a Out of memory error. With 4GB of RAM for the pf machine I don't run into this issue any more (pfsetvlan takes 1GB alone).
This was not an easy find, despite the obvious errors at some point, as runing ipset as pf user lead to an other error (Kernel: operation not permitted) making me think of an sudoers/access right issue and also with a DHCP renew/reboot of the client it would trigger something that would make pf to work and give access at the end (which was a workaround used since then).
I did not came across such memory issue with "modern" OS since a while and that's also probably why I did not think of it at first.

Issue History
Date Modified	Username	Field	Change
2013-06-25 11:47	JasonFell	New Issue
2013-06-26 05:06	rivan	Note Added: 0003330
2013-07-02 06:15	JasonFell	Note Added: 0003331
2013-07-02 22:28	rivan	Note Added: 0003332
2013-07-02 22:29	rivan	Note Edited: 0003332
2013-07-03 04:31	JasonFell	Note Added: 0003333
2013-07-03 04:32	JasonFell	File Added: Packetfence Output after secure redirect disable.txt
2013-07-04 23:01	rivan	Note Added: 0003334
2013-07-04 23:01	rivan	Note Edited: 0003334
2013-07-09 05:47	JasonFell	Note Added: 0003335
2013-07-15 07:26	JasonFell	Note Edited: 0003335
2013-07-18 03:48	JasonFell	Note Added: 0003342
2013-07-18 03:49	JasonFell	File Added: Packetfence-successful_activation.log
2013-07-31 20:13	fdurand	Note Added: 0003360
2013-08-01 03:39	jvlien	Note Added: 0003362
2013-08-01 08:12	fdurand	Note Added: 0003365
2013-08-01 08:40	jvlien	Note Added: 0003367
2013-08-01 08:41	jvlien	Note Added: 0003368
2013-08-01 09:14	fdurand	Note Added: 0003369
2013-08-01 10:03	jvlien	Note Added: 0003370
2013-08-01 10:04	jvlien	Note Edited: 0003368
2013-08-01 15:40	fdurand	Note Added: 0003371
2013-08-02 02:57	jvlien	Note Added: 0003374
2013-08-02 09:31	fdurand	Note Added: 0003377
2013-08-02 09:41	jvlien	Note Added: 0003378
2013-08-05 11:16	fdurand	Note Added: 0003384
2013-08-05 13:05	jvlien	Note Added: 0003385
2013-08-05 13:56	fdurand	Note Added: 0003386
2013-08-06 03:11	jvlien	Note Added: 0003387
2013-09-03 05:20	dranix	Note Added: 0003434
2013-09-11 23:14	dranix	Note Added: 0003442
2013-09-17 02:57	dranix	Note Added: 0003451
2013-12-08 03:30	showy	Note Added: 0003479
2014-09-11 04:29	jvlien	Note Added: 0003580

Relationships