6100 SLOW in comparison to Protectli FW6E

bmeeks

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

@bmeeks You’re welcomed. Hope to see the results in pfsense soon

The pull request is posted now and awaiting review and approval by the Netgate team. They have some more important fires to beat out relative to the just released 23.01 update, but I expect them to get the new package version merged soon. It will show as Suricata-6.0.10 when released. The pull request for updating the binary portion is here: https://github.com/pfsense/FreeBSD-ports/pull/1226.

bmeeks

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

@bmeeks You’re welcomed. Hope to see the results in pfsense soon

The pull requests for updating Suricata have been accepted by the Netgate team. For the moment, automatic package builds are disabled in the 23.01 branch so the new version will not show up yet. The automatic builds should be re-enabled soon, and after that you will see a Suricata-6.0.10 package available containing the latest fixes.

Once you have that installed, go to the INTERFACE SETTINGS tab and change the Run Mode under the Performance and Detection Engine Settings section to "workers", save the change, and then restart Suricata on the interface. You should see a marked increase in throughput using Inline IPS Mode after that. And with the new fix, the stall/hang condition is hopefully gone!

manilx

@bmeeks Awesome. Once it's there I'll try it immediately and post back here.

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.