6100 SLOW in comparison to Protectli FW6E

bmeeks

@manilx:
The new updated Suricata package containing the netmap stall fix has been posted now for pfSense 23.01. The new Suricata package version is 6.0.10_1.

I am interested in how this new package performs for you. For peak throughput when using Inline IPS Mode, remember to change the Run Mode parameter from its default of autofp to workers. Save that change and then restart Suricata on the interface.

manilx

@bmeeks Hi. Updated suricata. Changed run mode to workers.
Restarted on interface. Doen't start. Tried several times to restart, doesn't.
Rebooted. Suricata not started.
reverted to snaphot (updated suricata but not workers mode). Working.

bmeeks

@manilx said in 6100 SLOW in comparison to Protectli FW6E:

@bmeeks Hi. Updated suricata. Changed run mode to workers.
Restarted on interface. Doen't start. Tried several times to restart, doesn't.
Rebooted. Suricata not started.
reverted to snaphot (updated suricata but not workers mode). Working.

Dang! Post the output of the suricata.log file for a failed startup in workers run mode.

manilx

@bmeeks Will have to boot back to other snapshot and try.

manilx

@manilx

21/2/2023 -- 20:14:21 - <Notice> -- This is Suricata version 6.0.10 RELEASE running in SYSTEM mode
21/2/2023 -- 20:14:21 - <Info> -- CPUs/cores online: 8
21/2/2023 -- 20:14:22 - <Info> -- HTTP memcap: 67108864
21/2/2023 -- 20:14:22 - <Info> -- Netmap: Setting IPS mode
21/2/2023 -- 20:14:22 - <Info> -- fast output device (regular) initialized: alerts.log
21/2/2023 -- 20:14:22 - <Info> -- http-log output device (regular) initialized: http.log
21/2/2023 -- 20:14:24 - <Info> -- 1 rule files processed. 6453 rules successfully loaded, 0 rules failed
21/2/2023 -- 20:14:24 - <Warning> -- [ERRCODE: SC_ERR_EVENT_ENGINE(210)] - can't suppress sid 2260002, gid 1: unknown rule
21/2/2023 -- 20:14:24 - <Info> -- Threshold config parsed: 2 rule(s) found
21/2/2023 -- 20:14:24 - <Info> -- 6453 signatures processed. 910 are IP-only rules, 0 are inspecting packet payload, 5376 inspect application layer, 108 are decoder event only
21/2/2023 -- 20:14:25 - <Info> -- Going to use 8 thread(s)
21/2/2023 -- 20:14:26 - <Info> -- devname [fd: 6] netmap:ix3-0/R@conf:host-rings=8 ix3 opened
21/2/2023 -- 20:14:26 - <Info> -- devname [fd: 7] netmap:ix3^0/T@conf:host-rings=8 ix3^ opened
21/2/2023 -- 20:14:26 - <Info> -- devname [fd: 11] netmap:ix3-1/R ix3 opened
21/2/2023 -- 20:14:26 - <Info> -- devname [fd: 12] netmap:ix3^1/T ix3^ opened
21/2/2023 -- 20:14:26 - <Info> -- devname [fd: 14] netmap:ix3-2/R ix3 opened
21/2/2023 -- 20:14:27 - <Info> -- devname [fd: 15] netmap:ix3^2/T ix3^ opened
21/2/2023 -- 20:14:27 - <Info> -- devname [fd: 16] netmap:ix3-3/R ix3 opened
21/2/2023 -- 20:14:27 - <Info> -- devname [fd: 17] netmap:ix3^3/T ix3^ opened
21/2/2023 -- 20:14:27 - <Info> -- devname [fd: 18] netmap:ix3-4/R ix3 opened
21/2/2023 -- 20:14:28 - <Info> -- devname [fd: 19] netmap:ix3^4/T ix3^ opened
21/2/2023 -- 20:14:28 - <Info> -- devname [fd: 20] netmap:ix3-5/R ix3 opened
21/2/2023 -- 20:14:28 - <Info> -- devname [fd: 21] netmap:ix3^5/T ix3^ opened
21/2/2023 -- 20:14:28 - <Info> -- devname [fd: 22] netmap:ix3-6/R ix3 opened
21/2/2023 -- 20:14:28 - <Info> -- devname [fd: 23] netmap:ix3^6/T ix3^ opened
21/2/2023 -- 20:14:29 - <Info> -- devname [fd: 24] netmap:ix3-7/R ix3 opened
21/2/2023 -- 20:14:29 - <Info> -- devname [fd: 25] netmap:ix3^7/T ix3^ opened
21/2/2023 -- 20:14:29 - <Info> -- Going to use 8 thread(s)
21/2/2023 -- 20:14:29 - <Info> -- devname [fd: 26] netmap:ix3^0/R@conf:host-rings=8 ix3^ opened
21/2/2023 -- 20:14:29 - <Info> -- devname [fd: 27] netmap:ix3-0/T@conf:host-rings=8 ix3 opened
21/2/2023 -- 20:14:30 - <Info> -- devname [fd: 28] netmap:ix3^1/R ix3^ opened
21/2/2023 -- 20:14:30 - <Info> -- devname [fd: 29] netmap:ix3-1/T ix3 opened
21/2/2023 -- 20:14:30 - <Info> -- devname [fd: 30] netmap:ix3^2/R ix3^ opened
21/2/2023 -- 20:14:31 - <Info> -- devname [fd: 31] netmap:ix3-2/T ix3 opened
21/2/2023 -- 20:14:31 - <Info> -- devname [fd: 32] netmap:ix3^3/R ix3^ opened
21/2/2023 -- 20:14:31 - <Info> -- devname [fd: 33] netmap:ix3-3/T ix3 opened
21/2/2023 -- 20:14:31 - <Info> -- devname [fd: 34] netmap:ix3^4/R ix3^ opened
21/2/2023 -- 20:14:31 - <Info> -- devname [fd: 35] netmap:ix3-4/T ix3 opened
21/2/2023 -- 20:14:32 - <Info> -- devname [fd: 36] netmap:ix3^5/R ix3^ opened
21/2/2023 -- 20:14:32 - <Info> -- devname [fd: 37] netmap:ix3-5/T ix3 opened
21/2/2023 -- 20:14:32 - <Error> -- [ERRCODE: SC_ERR_POOL_INIT(66)] - alloc error
21/2/2023 -- 20:14:32 - <Error> -- [ERRCODE: SC_ERR_POOL_INIT(66)] - pool grow failed
21/2/2023 -- 20:14:32 - <Error> -- [ERRCODE: SC_ERR_MEM_ALLOC(1)] - failed to setup/expand stream session pool. Expand stream.memcap?
21/2/2023 -- 20:14:32 - <Info> -- devname [fd: 38] netmap:ix3^6/R ix3^ opened
21/2/2023 -- 20:14:32 - <Info> -- devname [fd: 39] netmap:ix3-6/T ix3 opened
21/2/2023 -- 20:14:32 - <Error> -- [ERRCODE: SC_ERR_POOL_INIT(66)] - alloc error
21/2/2023 -- 20:14:32 - <Error> -- [ERRCODE: SC_ERR_POOL_INIT(66)] - pool grow failed
21/2/2023 -- 20:14:32 - <Error> -- [ERRCODE: SC_ERR_MEM_ALLOC(1)] - failed to setup/expand stream session pool. Expand stream.memcap?
21/2/2023 -- 20:14:33 - <Info> -- devname [fd: 40] netmap:ix3^7/R ix3^ opened
21/2/2023 -- 20:14:33 - <Info> -- devname [fd: 41] netmap:ix3-7/T ix3 opened
21/2/2023 -- 20:14:33 - <Error> -- [ERRCODE: SC_ERR_POOL_INIT(66)] - alloc error
21/2/2023 -- 20:14:33 - <Error> -- [ERRCODE: SC_ERR_POOL_INIT(66)] - pool grow failed
21/2/2023 -- 20:14:33 - <Error> -- [ERRCODE: SC_ERR_MEM_ALLOC(1)] - failed to setup/expand stream session pool. Expand stream.memcap?
21/2/2023 -- 20:14:33 - <Error> -- [ERRCODE: SC_ERR_THREAD_INIT(49)] - thread "W#06-ix3^" failed to initialize: flags 0145
21/2/2023 -- 20:14:33 - <Error> -- [ERRCODE: SC_ERR_FATAL(171)] - Engine initialization failed, aborting...

manilx

@manilx Also changing back to autofp (when suricata doesn't start any longer) and trying to start on the interface results in it NOT starting.
Will revert to working snapshot! Not further testing for the time being.

bmeeks

@manilx:
Your problem has a simple fix. Using more threads and a high core-count CPU requires more TCP stream-memcap memory be allocated. Go to the FLOW/STREAM tab and increase the amount of Stream Memory Cap under Stream Engine Settings. Try 256 MB and continue increasing in 128 MB or 256 MB chunks until Suricata starts succesfully.

This line in the log is the problem:

21/2/2023 -- 20:14:32 - <Error> -- [ERRCODE: SC_ERR_MEM_ALLOC(1)] - failed to setup/expand stream session pool. Expand stream.memcap?

Likely this is triggered by a change in the 6.0.10 binary upstream. Previously Suricata on pfSense was running the 6.0.8 binary. The default is 128 MB, and that may not be enough with some hardware setups.

bmeeks

@manilx said in 6100 SLOW in comparison to Protectli FW6E:

@manilx Also changing back to autofp (when suricata doesn't start any longer) and trying to start on the interface results in it NOT starting.
Will revert to working snapshot! Not further testing for the time being.

I have posted a Release Notes thread for the new Suricata package here: https://forum.netgate.com/topic/178138/suricata-6-0-10_1-update-for-pfsense-plus-23-01-release-notes. You can check it out for details on what has changed.

Your startup error is solely due to not having enough TCP stream memory. Raising the Stream Memcap value will fix you up. You were likely already sitting on the edge. This is a not too uncommon occurrence when users have high core-count CPUs.

manilx

@bmeeks OK. Doubled it. Suricata starts. Did speedtest. Can't find any difference from default setting actually (with this unit).

bmeeks

@manilx said in 6100 SLOW in comparison to Protectli FW6E:

@bmeeks OK. Doubled it. Suricata starts. Did speedtest. Can't find any difference from default setting actually (with this unit).

Glad it started up. I was pretty confident the Stream Memory increase would fix it.

As for speed, if I recall you were already pretty much at link saturation, so not much room for improvement. But now, it should not experience any random stalls. The other Suricata developer and I are pretty confident we found and fixed that problem. It was the same problem that plagued OPNsense as well when using Suricata.

manilx

@bmeeks Awesome!
I will report here if I find any further issues.

manilx

@manilx I got this error during the night. Never got this before:

pfsense: pfSense.home.lan
PHP ERROR: Type: 1, File: /usr/local/pkg/suricata/suricata_check_for_rule_updates.php, Line: 820, Message: Uncaught ValueError: gettext(): Argument #1 ($message) is too long in /usr/local/pkg/suricata/suricata_check_for_rule_updates.php:820
Stack trace:
#0 /usr/local/pkg/suricata/suricata_check_for_rule_updates.php(820): gettext('- Snort rules: ...')
#1 {main}
thrown

bmeeks

@manilx said in 6100 SLOW in comparison to Protectli FW6E:

@manilx I got this error during the night. Never got this before:

pfsense: pfSense.home.lan
PHP ERROR: Type: 1, File: /usr/local/pkg/suricata/suricata_check_for_rule_updates.php, Line: 820, Message: Uncaught ValueError: gettext(): Argument #1 ($message) is too long in /usr/local/pkg/suricata/suricata_check_for_rule_updates.php:820
Stack trace:
#0 /usr/local/pkg/suricata/suricata_check_for_rule_updates.php(820): gettext('- Snort rules: ...')
#1 {main}
thrown

Hmm... never seen that one pop up before. I will look into it. First guess is something changed in the behavior of the third-party gettext() library used for language translation.

bmeeks

@manilx:
One more question, please. Where are you located, and is English perhaps not the primary language there?

Trying to figure out why this has not cropped up in neither my testing nor from the testing done by others in the snapshots development cycle.

manilx

@bmeeks I'm located in Portugal. But my pfsense and all config is in english

manilx

@manilx P.S. And this is new to the latest suricata.

bmeeks

@manilx said in 6100 SLOW in comparison to Protectli FW6E:

@bmeeks I'm located in Portugal. But my pfsense and all config is in english

So all the displayed text on the firewall is in English as well? What rules packages do you have enabled on the GLOBAL SETTINGS tab? Do you have an Extra Rules downloads added? I will need to reproduce your rules download setup to see if I can duplicate the error.

bmeeks

@manilx said in 6100 SLOW in comparison to Protectli FW6E:

@manilx P.S. And this is new to the latest suricata.

Yes, but the underlying pfSense GUI subsystem has undergone a huge update from PHP 7.4 to PHP 8.1. That is where all the GUI issues with packages and even pfSense itself are coming from. Thousands of lines of PHP code had to be changed in order to be compatible with PHP 8.1. Some got missed. A lot of stuff showed up and got fixed during the DEVEL snapshot testing, but not always everything. Different users can have unique configurations that trigger a PHP issue with the change to 8.1.

manilx

@bmeeks Yes! All in english.
ScreenShot 2023-02-22 at 13.58.11.png

bmeeks

@manilx said in 6100 SLOW in comparison to Protectli FW6E:

@bmeeks Yes! All in english.

Okay... that helps. So if you enable the Snort Subscriber Rules you get the error. I will try and reproduce in my test virtual machine.