Compatibility with PfSense 2.7.0 alpha

woodsb02 commented 1 year ago

I've recently updated from PfSense 2.6.0 to the devel snapshot 2.7.0.a.20221206.0600.

I started receiving error notifications in the Pfsense web interface every 30 seconds with the message below.

PHP ERROR: Type: 1, File: /etc/inc/util.inc, Line: 220, Message: Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:220
Stack trace:
#0 /etc/inc/util.inc(220): flock(Resource id #11, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #11)
#2 {main}
  thrown

Once I disabled the hass-pfsense integration in home assistant, I stopped receiving these errors. I suspect there is a compatibility issue with the new version of pfsense, that might require some changes to this hass-Pfsense plugin.

To try and assist debugging this, please see below extracts from the Pfsense files in the stack trace (with a few lines of context preceding the trouble lines):

/etc/inc/util.inc (lines 217-220):

/* unlock configuration file */
function unlock($cfglckkey = 0) {
    if (!is_null($cfglckkey)) {
        @flock($cfglckkey, LOCK_UN);

/usr/local/www/xmlrpc.php (Lines 976-990):


$xmlrpclockkey = lock('xmlrpc', LOCK_EX);

XML_RPC2_Backend::setBackend('php');
$HTTP_RAW_POST_DATA = file_get_contents('php://input');

$options = array(
    'prefix' => 'pfsense.',
    'encoding' => 'utf-8',
    'autoDocument' => false,
);

$server = XML_RPC2_Server::create(new pfsense_xmlrpc_server(), $options);
$server->handleCall();

unlock($xmlrpclockkey);

travisghansen commented 1 year ago

I’m sure it can be fixed but it will be a little while before I can take a look.

w1tw0lf commented 1 year ago

I can confirm the issue, as I am experiencing the exact same issue.

illnesse commented 1 year ago

same here

amd64
14.0-CURRENT
FreeBSD 14.0-CURRENT #0 devel-main-n255825-17d2b04a49e: Mon Dec 26 06:29:05 UTC 2022     root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-master-main/obj/amd64/x5bStUzr/var/jenkins/workspace/pfSense-CE-snapshots-master-main/sources/FreeBSD-src-dev

Crash report details:

PHP Errors:
[31-Dec-2022 20:25:05 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #13, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #13)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:08 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:08 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:08 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:08 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:08 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:08 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:08 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:08 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:08 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:09 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:09 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:09 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:09 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174
[31-Dec-2022 20:25:18 Europe/Berlin] PHP Fatal error:  Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
  thrown in /etc/inc/util.inc on line 174

No FreeBSD crash data found.

davericher commented 1 year ago

Likewise, it seems downgrading Pfsense is not as simple as I imagined it to be 👎

travisghansen commented 1 year ago

I’ll probably have some time in the next week or so to take a look.

travisghansen commented 1 year ago

Can someone edit line 173 in /etc/inc/util.inc and change the following line:

FROM
if (!is_null($cfglckkey)) {

TO
if (!is_null($cfglckkey) && is_resource($cfglckkey)) {

Probably best to restart after but it may work without a restart. I want to know if there are any other bugs/issues.

davericher commented 1 year ago

Can someone edit line 173 in /etc/inc/util.inc and change the following line:
FROM
if (!is_null($cfglckkey)) {

TO
if (!is_null($cfglckkey) && is_resource($cfglckkey)) {
Probably best to restart after but it may work without a restart. I want to know if there are any other bugs/issues.

That does resolve the lock file issue, however

PHP ERROR: Type: 1, File: /usr/local/www/xmlrpc.php(147) : eval()'d code, Line: 14, Message: Uncaught TypeError: Cannot access offset of type string on string in /usr/local/www/xmlrpc.php(147) : eval()'d code:14
Stack trace:
#0 /usr/local/www/xmlrpc.php(147): eval()
#1 /usr/local/share/pear/XML/RPC2/Server/CallHandler/Instance.php(141): pfsense_xmlrpc_server->exec_php('\nini_set('displ...')
#2 /usr/local/share/pear/XML/RPC2/Backend/Php/Server.php(135): XML_RPC2_Server_Callhandler_Instance->__call('pfsense.exec_ph...', Array)
#3 /usr/local/share/pear/XML/RPC2/Backend/Php/Server.php(99): XML_RPC2_Backend_Php_Server->getResponse()
#4 /usr/local/www/xmlrpc.php(988): XML_RPC2_Backend_Php_Server->handleCall()
#5 {main}
thrown @ 2023-01-15 15:06:11
PHP ERROR: Type: 1, File: /usr/local/www/xmlrpc.php(147) : eval()'d code, Line: 14, Message: Uncaught TypeError: Cannot access offset of type string on string in /usr/local/www/xmlrpc.php(147) : eval()'d code:14
Stack trace:
#0 /usr/local/www/xmlrpc.php(147): eval()
#1 /usr/local/share/pear/XML/RPC2/Server/CallHandler/Instance.php(141): pfsense_xmlrpc_server->exec_php('\nini_set('displ...')
#2 /usr/local/share/pear/XML/RPC2/Backend/Php/Server.php(135): XML_RPC2_Server_Callhandler_Instance->__call('pfsense.exec_ph...', Array)
#3 /usr/local/share/pear/XML/RPC2/Backend/Php/Server.php(99): XML_RPC2_Backend_Php_Server->getResponse()
#4 /usr/local/www/xmlrpc.php(988): XML_RPC2_Backend_Php_Server->handleCall()
#5 {main}
thrown @ 2023-01-15 15:06:22

Does not look like we are out of the water yet. Seems to be an eval line So I am thinking maybe the plugin is using something that was deprecated in PHP 8.

This seems to be the code it is getting hung up on

ini_set('display_errors', 0);

// release the mutex immediately so other api calls can go through
// as this one can take a minute
require_once '/etc/inc/util.inc';
global $xmlrpclockkey;
unlock($xmlrpclockkey);

require_once '/etc/inc/service-utils.inc';
// only returns enabled services currently
$s = get_services();
$services = [];
foreach($s as $service) {
  if (!is_array($service)) {
      continue;
  }
  if (!empty($service)) {
    $services[] = $service;
  }
}

$toreturn = [
  // function get_services()
  "data" => $services,
];

// wrapping this in json_encode and then unwrapping in python prevents funny XMLRPC NULL encoding errors
// https://github.com/travisghansen/hass-pfsense/issues/35
$toreturn_real = $toreturn;
$toreturn = [];
$toreturn["real"] = json_encode($toreturn_real);

travisghansen commented 1 year ago

I've just done a fresh install of using the latest 2.7 and it works out of the box without any hacks at all. I'm wondering if there is some specific package that's causing the issue. What extras do you have installed?

woodsb02 commented 1 year ago

On the box where I am experiencing the problem I have the following packages installed: Acme, Avahi, iperf, lldpd, nmap, ntopng, status_traffic_totals, telegraf, WireGuard.

I also wonder if it could be a feature of upgrading - if installing those packages doesn’t help, it might be worth installing pfsense 2.6, integrating with home assistant, and then upgrading.

I’m also using a non-admin user with the System - HA node sync privilege - in case that has anything to do with it.

travisghansen commented 1 year ago

I installed all those packages and used a non-admin/non-root user and still no errors :(

I may need someone to message me privately and let me run some api calls directly against their firewall or do that themselves to see where the failure is :(

davericher commented 1 year ago

If you want to provide some calls I can run I would more than happy to assist.

spyfly commented 1 year ago

Also getting these errors with the pfSense+ 23.01 BETA.

PHP ERROR: Type: 1, File: /etc/inc/util.inc, Line: 174, Message: Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}

illnesse commented 1 year ago

Any progress on this? i'm happy to help

Version | 2.7.0-DEVELOPMENT (amd64)built on Fri Jan 20 03:01:02 UTC 2023FreeBSD 14.0-CURRENT

acme | 0.7.3_1 | arping | 1.2.2_4 | Avahi | 2.2_3 | Filer | 0.60.6_7 | iperf | 3.0.3 | nmap | 1.4.4_7 | pfBlockerNG-devel | 3.1.0_19 | WireGuard | 0.1.6_5

travisghansen commented 1 year ago

I’ll see if I can add some better logging. If not someone will need to setup a python dev env and start running through all the calls to see which is making it crash.

travisghansen commented 1 year ago

Does anyone have corresponding logs from hass?

illnesse commented 1 year ago

there doesn't seem to be anything pfsense related in hass logs (while pfsense is barfing loads of errors), tried restarting it too

travisghansen commented 1 year ago

I just released v0.5.11. Try it out and see if you get something logged into the hass logs now. The primary purpose is to figure out which method(s) is causing the error to begin with. Usually when I know which method it is I can add necessary robustness around the code to handle any possible edge cases.

illnesse commented 1 year ago

Still nothing pfsense related in the hass log, only

2023-01-23 17:04:39.689 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration pfsense which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant

pfsense still spamming

PHP ERROR: Type: 1, File: /etc/inc/util.inc, Line: 174, Message: Uncaught TypeError: flock(): supplied resource is not a valid stream resource in /etc/inc/util.inc:174
Stack trace:
#0 /etc/inc/util.inc(174): flock(Resource id #10, 3)
#1 /usr/local/www/xmlrpc.php(990): unlock(Resource id #10)
#2 {main}
thrown @ 2023-01-23 17:06:12

illnesse commented 1 year ago

Oh here we go:

2023-01-23 17:09:02.428 ERROR (SyncWorker_0) [custom_components.pfsense.pypfsense] Unexpected get_system_info error err=gaierror(-3, 'Try again'), type(err)=<class 'socket.gaierror'>
2023-01-23 17:09:02.430 ERROR (MainThread) [custom_components.pfsense] Unexpected error fetching pfSense pfSense state data: [Errno -3] Try again
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 225, in _async_refresh
    self.data = await self._async_update_data()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 181, in _async_update_data
    return await self.update_method()
  File "/config/custom_components/pfsense/__init__.py", line 96, in async_update_data
    await hass.async_add_executor_job(lambda: data.update())
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/config/custom_components/pfsense/__init__.py", line 96, in <lambda>
    await hass.async_add_executor_job(lambda: data.update())
  File "/config/custom_components/pfsense/__init__.py", line 316, in update
    self._state["system_info"] = self._get_system_info()
  File "/config/custom_components/pfsense/__init__.py", line 229, in inner
    response = func(*args, **kwargs)
  File "/config/custom_components/pfsense/__init__.py", line 240, in _get_system_info
    return self._client.get_system_info()
  File "/config/custom_components/pfsense/pypfsense/__init__.py", line 94, in inner
    raise err
  File "/config/custom_components/pfsense/pypfsense/__init__.py", line 91, in inner
    return func(*args, **kwargs)
  File "/config/custom_components/pfsense/pypfsense/__init__.py", line 275, in get_system_info
    response = self._exec_php(script)
  File "/config/custom_components/pfsense/pypfsense/__init__.py", line 81, in inner
    response = func(*args, **kwargs)
  File "/config/custom_components/pfsense/pypfsense/__init__.py", line 124, in _exec_php
    response = self._get_proxy().pfsense.exec_php(script)
  File "/usr/local/lib/python3.10/xmlrpc/client.py", line 1122, in __call__
    return self.__send(self.__name, args)
  File "/usr/local/lib/python3.10/xmlrpc/client.py", line 1464, in __request
    response = self.__transport.request(
  File "/usr/local/lib/python3.10/xmlrpc/client.py", line 1166, in request
    return self.single_request(host, handler, request_body, verbose)
  File "/usr/local/lib/python3.10/xmlrpc/client.py", line 1178, in single_request
    http_conn = self.send_request(host, handler, request_body, verbose)
  File "/usr/local/lib/python3.10/xmlrpc/client.py", line 1291, in send_request
    self.send_content(connection, request_body)
  File "/usr/local/lib/python3.10/xmlrpc/client.py", line 1321, in send_content
    connection.endheaders(request_body)
  File "/usr/local/lib/python3.10/http/client.py", line 1277, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.10/http/client.py", line 1037, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.10/http/client.py", line 975, in send
    self.connect()
  File "/usr/local/lib/python3.10/http/client.py", line 1447, in connect
    super().connect()
  File "/usr/local/lib/python3.10/http/client.py", line 941, in connect
    self.sock = self._create_connection(
  File "/usr/local/lib/python3.10/socket.py", line 824, in create_connection
    for res in getaddrinfo(host, port, 0, SOCK_STREAM):
  File "/usr/local/lib/python3.10/socket.py", line 955, in getaddrinfo
    for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
socket.gaierror: [Errno -3] Try again

illnesse commented 1 year ago

there's also this:

2023-01-23 17:09:32.409 ERROR (SyncWorker_9) [custom_components.pfsense.pypfsense] Unexpected get_system_info error err=gaierror(-2, 'Name does not resolve'), type(err)=<class 'socket.gaierror'>
2023-01-23 17:09:32.411 ERROR (MainThread) [custom_components.pfsense] Unexpected error fetching pfSense pfSense state data: [Errno -2] Name does not resolve

probably unrelated, it does resolve fine.

the resolve errors stopped, i reloaded the integration, restarting hass now

looks like at least some things are working, it found an update:

sensors seem to update fine as well (except DHCP leases, which definitely should be > 0)

but again nothing in hass log, the usual errors in pfsense log

travisghansen commented 1 year ago

Those are both pretty low level errors I am not sure the integration can solve. It appears you have some connectivity issues at a fundamental level. Having said that, that doesn’t explain why you would have related php errors on pfsense…

illnesse commented 1 year ago

Those are both pretty low level errors I am not sure the integration can solve. It appears you have some connectivity issues at a fundamental level. Having said that, that doesn’t explain why you would have related php errors on pfsense…

Yeah like i said, those errors must be unrelated. Another restart fixed those but i'm still not getting any pfsense related logs in hass. the sensors work (except dhcp) but meanwhile in pfsense it is raining errors

travisghansen commented 1 year ago

Checkout the project and then do the following:

[[ ! -f "venv/bin/activate" ]] && virtualenv venv || true
source venv/bin/activate
pip install --upgrade -r requirements_dev.txt

Then create a file in the root of project called api.py

import os
import sys
import json

from custom_components.pfsense.pypfsense import Client

url      = os.environ.get("PFSENSE_URL")
username = os.environ.get("PFSENSE_USERNAME")
password = os.environ.get("PFSENSE_PASSWORD")

client = Client(url, username, password, {"verify_ssl": False})

#print(client.get_services())
#print(json.dumps(client.get_carp_interfaces()))
#print(client.get_carp_status())

Set the env vars as appropriate and then run python api.py commenting out the method you want to invoke. You can see what methods the integration invokes here: https://github.com/travisghansen/hass-pfsense/blob/main/custom_components/pfsense/__init__.py#L316-L345

Basically you'll need to turn off the integration in hass, clear the error log in pfsense, and then start going through the methods 1 at a time until you find whatever is causing the spam :(

spyfly commented 1 year ago

So it seems like

print(client.get_services()) # Creates 9 Errors every run
print(json.dumps(client.get_carp_interfaces())) # Creates 1 Error every run
print(client.get_carp_status()) # Creates 1 Error every run

I believe this is a more general issue in the way the calls are made.

travisghansen commented 1 year ago

Did other calls produce no errors? And which error(s) did the mentioned calls produce?

travisghansen commented 1 year ago

This seems to have been cleaned up in more recent versions..

function unlock($cfglckkey = 0)
{
        if (!is_resource($cfglckkey))
                return;
...

spyfly commented 1 year ago

Seems to work now without issues

travisghansen / hass-pfsense

Compatibility with PfSense 2.7.0 alpha #123