Suricata process dying due to hyperscan problem

bmeeks

@masons said in Suricata process dying due to hyperscan problem:

I loaded the Suricata package that you provided. I did not disable ASLR, so when I started Suricata with pattern matcher set to to "Auto", the PC interface Suricata instance immediately crashed. Below is the gdb output you asked for.

Core was generated by `/usr/local/bin/suricata -i vtnet0.700 -D -c /usr/local/etc/suricata/suricata_238'.
Program terminated with signal SIGSEGV, Segmentation fault.
Address not mapped to object.
#0  0x0000000000bf531a in AppLayerProtoDetectPMGetIpprotos (alproto=22, ipprotos=0x76a19745bd6 "") at app-layer-detect-proto.c:1177
1177    app-layer-detect-proto.c: No such file or directory.
[Current thread is 1 (LWP 100363)]
warning: Missing auto-load script at offset 0 in section .debug_gdb_scripts
of file /usr/local/bin/suricata.
Use `info auto-load python-scripts [REGEXP]' to list them.
(gdb) bt
#0  0x0000000000bf531a in AppLayerProtoDetectPMGetIpprotos (alproto=22, ipprotos=0x76a19745bd6 "") at app-layer-detect-proto.c:1177
#1  0x0000000000bf5193 in AppLayerProtoDetectSupportedIpprotos (alproto=22, ipprotos=0x76a19745bd6 "") at app-layer-detect-proto.c:2054
#2  0x0000000000b2c299 in SigParseProto (s=0x76a19745bc0, protostr=0x822b0ce48 "dhcp") at detect-parse.c:1107
#3  0x0000000000b2af88 in SigParseBasics (de_ctx=0x76a17580000, s=0x76a19745bc0, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)", parser=0x822b0ae48, addrs_direction=0 '\000') at detect-parse.c:1375
#4  0x0000000000b28997 in SigParse (de_ctx=0x76a17580000, s=0x76a19745bc0, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)", addrs_direction=0 '\000', parser=0x822b0ae48) at detect-parse.c:1456
#5  0x0000000000b27024 in SigInitHelper (de_ctx=0x76a17580000, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)", dir=0 '\000') at detect-parse.c:2147
#6  0x0000000000b26d86 in SigInit (de_ctx=0x76a17580000, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)") at detect-parse.c:2304
#7  0x0000000000b2794d in DetectEngineAppendSig (de_ctx=0x76a17580000, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)") at detect-parse.c:2602
#8  0x0000000000b5cd42 in DetectLoadSigFile (de_ctx=0x76a17580000, sig_file=0x76a1501c780 "/usr/local/etc/suricata/suricata_23822_vtnet0.700/rules/suricata.rules", goodsigs=0x822b1d0fc, badsigs=0x822b1d0f8) at detect-engine-loader.c:165
#9  0x0000000000b5bc0e in ProcessSigFiles (de_ctx=0x76a17580000, pattern=0x76a1501c6e0 "/usr/local/etc/suricata/suricata_23822_vtnet0.700/rules/suricata.rules", st=0x76a175813f0, good_sigs=0x822b1d0fc, bad_sigs=0x822b1d0f8) at detect-engine-loader.c:249
#10 0x0000000000b5b58c in SigLoadSignatures (de_ctx=0x76a17580000, sig_file=0x0, sig_file_exclusive=0) at detect-engine-loader.c:307
#11 0x0000000000ab9c1e in LoadSignatures (de_ctx=0x76a17580000, suri=0x1e27b90 <suricata>) at suricata.c:2415
#12 0x0000000000ab99da in PostConfLoadedDetectSetup (suri=0x1e27b90 <suricata>) at suricata.c:2562
#13 0x0000000000abb4ed in SuricataMain (argc=8, argv=0x822b1d2f0) at suricata.c:2971
#14 0x0000000000ab9222 in main (argc=8, argv=0x822b1d2f0) at main.c:22

And the output from bt full.

(gdb) bt full
#0  0x0000000000bf531a in AppLayerProtoDetectPMGetIpprotos (alproto=22, ipprotos=0x76a19745bd6 "") at app-layer-detect-proto.c:1177
        s = 0x76a01000000
        x = 0
        pm_ctx = 0x1e48de0 <alpd_ctx+144>
        j = 0
        ipproto = 17 '\021'
        i = 1 '\001'
#1  0x0000000000bf5193 in AppLayerProtoDetectSupportedIpprotos (alproto=22, ipprotos=0x76a19745bd6 "") at app-layer-detect-proto.c:2054
No locals.
#2  0x0000000000b2c299 in SigParseProto (s=0x76a19745bc0, protostr=0x822b0ce48 "dhcp") at detect-parse.c:1107
        r = -1
#3  0x0000000000b2af88 in SigParseBasics (de_ctx=0x76a17580000, s=0x76a19745bc0, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)", parser=0x822b0ae48, addrs_direction=0 '\000') at detect-parse.c:1375
        index = 0x822b08d4f "msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;"
        dup = "alert\000dhcp\000any\000any\000->\000any\000any\000(msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;\000\000 rev:2;\000\000\000\0002;\000\00064; rev:2;\000\000\000comman"...
#4  0x0000000000b28997 in SigParse (de_ctx=0x76a17580000, s=0x76a19745bc0, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)", addrs_direction=0 '\000', parser=0x822b0ae48) at detect-parse.c:1456
        ret = 8
#5  0x0000000000b27024 in SigInitHelper (de_ctx=0x76a17580000, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)", dir=0 '\000') at detect-parse.c:2147
        parser = {action = "alert", '\000' <repeats 8186 times>, protocol = "dhcp", '\000' <repeats 8187 times>, direction = "->", '\000' <repeats 8189 times>, src = "any", '\000' <repeats 8188 times>, dst = "any", '\000' <repeats 8188 times>, sp = "any", '\000' <repeats 8188 times>, dp = "any", '\000' <repeats 8188 times>,
          opts = "msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;", '\000' <repeats 8058 times>}
        sig = 0x76a19745bc0
        ret = 0
#6  0x0000000000b26d86 in SigInit (de_ctx=0x76a17580000, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)") at detect-parse.c:2304
        oldsignum = 685
        sig = 0x822b1af90
#7  0x0000000000b2794d in DetectEngineAppendSig (de_ctx=0x76a17580000, sigstr=0x822b1af90 "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)") at detect-parse.c:2602
        sig = 0x822b1aef0
        dup_sig = 41
#8  0x0000000000b5cd42 in DetectLoadSigFile (de_ctx=0x76a17580000, sig_file=0x76a1501c780 "/usr/local/etc/suricata/suricata_23822_vtnet0.700/rules/suricata.rules", goodsigs=0x822b1d0fc, badsigs=0x822b1d0f8) at detect-engine-loader.c:165
        len = 166
        sig = 0x76a19745a80
        good = 685
        bad = 0
        line = "alert dhcp any any -> any any (msg:\"SURICATA DHCP malformed options\"; app-layer-event:dhcp.malformed_options; classtype:protocol-command-decode; sid:2227000; rev:1;)\000\000rev:2;)\000\000\000\000;)\000\0004; rev:2;)\000\000\000omman"...
        offset = 0
        lineno = 694
        multiline = 0
        fp = 0x8334c85a0
#9  0x0000000000b5bc0e in ProcessSigFiles (de_ctx=0x76a17580000, pattern=0x76a1501c6e0 "/usr/local/etc/suricata/suricata_23822_vtnet0.700/rules/suricata.rules", st=0x76a175813f0, good_sigs=0x822b1d0fc, bad_sigs=0x822b1d0f8) at detect-engine-loader.c:249
        fname = 0x76a1501c780 "/usr/local/etc/suricata/suricata_23822_vtnet0.700/rules/suricata.rules"
        i = 0
        r = 0
        files = {gl_pathc = 1, gl_matchc = 1, gl_offs = 0, gl_flags = 0, gl_pathv = 0x76a1509aba0, gl_errfunc = 0x0, gl_closedir = 0x1, gl_readdir = 0x76a15012000, gl_opendir = 0x822b1d080, gl_lstat = 0x82d8566f8, gl_stat = 0x76a15012000}
#10 0x0000000000b5b58c in SigLoadSignatures (de_ctx=0x76a17580000, sig_file=0x0, sig_file_exclusive=0) at detect-engine-loader.c:307
        rule_files = 0x76a150b1400
        file = 0x76a150b1480
        sig_stat = 0x76a175813f0
        ret = 0
        sfile = 0x76a1501c6e0 "/usr/local/etc/suricata/suricata_23822_vtnet0.700/rules/suricata.rules"
        varname = "rule-files", '\000' <repeats 117 times>
        good_sigs = 0
        bad_sigs = 0
#11 0x0000000000ab9c1e in LoadSignatures (de_ctx=0x76a17580000, suri=0x1e27b90 <suricata>) at suricata.c:2415
No locals.
#12 0x0000000000ab99da in PostConfLoadedDetectSetup (suri=0x1e27b90 <suricata>) at suricata.c:2562
        mt_enabled = 0
        default_tenant = 0
        de_ctx = 0x76a17580000
#13 0x0000000000abb4ed in SuricataMain (argc=8, argv=0x822b1d2f0) at suricata.c:2971
        tracking = 0
        limit_nproc = 1
#14 0x0000000000ab9222 in main (argc=8, argv=0x822b1d2f0) at main.c:22
No locals.

Thank you. This crash is similar to @kiokoman's core dump. Suricata seems to be doing something improper within the App Layer protocols logic. In your case it is causing a Signal 11 segfault, but in his case it simply results in the Hyperscan library stopping on a passed-in parameter validation check which leads to Suricata shutting down with a Fatal Error. I may need to raise this again with upstream.

Still puzzled why I can't seem to reproduce it -- at least not yet.

kiokoman

@masons

could you tell me if the contents of this directory are the same as mine pls?

ls -la /usr/local/lib/libhs*

-rw-r--r--  1 root wheel 12342598 Dec  8 18:06 /usr/local/lib/libhs.a
lrwxr-xr-x  1 root wheel       10 Dec  8 18:07 /usr/local/lib/libhs.so -> libhs.so.5
lrwxr-xr-x  1 root wheel       14 Dec  8 18:07 /usr/local/lib/libhs.so.5 -> libhs.so.5.4.0
-rwxr-xr-x  1 root wheel  4521768 Dec  8 18:07 /usr/local/lib/libhs.so.5.4.0
-rw-r--r--  1 root wheel  1423432 Dec  8 18:05 /usr/local/lib/libhs_runtime.a
lrwxr-xr-x  1 root wheel       18 Dec  8 18:07 /usr/local/lib/libhs_runtime.so -> libhs_runtime.so.5
lrwxr-xr-x  1 root wheel       22 Dec  8 18:07 /usr/local/lib/libhs_runtime.so.5 -> libhs_runtime.so.5.4.0
-rwxr-xr-x  1 root wheel  1015368 Dec  8 18:07 /usr/local/lib/libhs_runtime.so.5.4.0

bmeeks

While not exactly the same, the failure locations I see in both of the suricata.core file back trace results look eerily like this old bug in that the failure is in the app-layer protocols section: https://redmine.openinfosecfoundation.org/issues/4273.

I wonder if there still might be an issue lurking in the logic even though the originally reported bug was fixed ??

I've sent both back trace results and @kiokoman's gdb.txt dump to the upstream developers asking for any insights they may have.

JonathanLee

@bmeeks Happy Holidays!!! I wanted to message you to say that.

masons

@kiokoman,

It looks like file sizes differ. I'm running pfSense 2.7.2 CE in this VM.

-rw-r--r--  1 root wheel  1421072 Jun 30 08:16 /usr/local/lib/libhs_runtime.a
lrwxr-xr-x  1 root wheel       18 Jun 30 08:17 /usr/local/lib/libhs_runtime.so -> libhs_runtime.so.5
lrwxr-xr-x  1 root wheel       22 Jun 30 08:17 /usr/local/lib/libhs_runtime.so.5 -> libhs_runtime.so.5.4.0
-rwxr-xr-x  1 root wheel  1007944 Jun 30 08:17 /usr/local/lib/libhs_runtime.so.5.4.0
-rw-r--r--  1 root wheel 12452892 Jun 30 08:17 /usr/local/lib/libhs.a
lrwxr-xr-x  1 root wheel       10 Jun 30 08:17 /usr/local/lib/libhs.so -> libhs.so.5
lrwxr-xr-x  1 root wheel       14 Jun 30 08:17 /usr/local/lib/libhs.so.5 -> libhs.so.5.4.0
-rwxr-xr-x  1 root wheel  4518952 Jun 30 08:17 /usr/local/lib/libhs.so.5.4.0

bmeeks

@JonathanLee said in Suricata process dying due to hyperscan problem:

@bmeeks Happy Holidays!!! I wanted to message you to say that.

Thank you. Same to you and your family.

bmeeks

@masons said in Suricata process dying due to hyperscan problem:

@kiokoman,

It looks like file sizes differ. I'm running pfSense 2.7.2 CE in this VM.

-rw-r--r--  1 root wheel  1421072 Jun 30 08:16 /usr/local/lib/libhs_runtime.a
lrwxr-xr-x  1 root wheel       18 Jun 30 08:17 /usr/local/lib/libhs_runtime.so -> libhs_runtime.so.5
lrwxr-xr-x  1 root wheel       22 Jun 30 08:17 /usr/local/lib/libhs_runtime.so.5 -> libhs_runtime.so.5.4.0
-rwxr-xr-x  1 root wheel  1007944 Jun 30 08:17 /usr/local/lib/libhs_runtime.so.5.4.0
-rw-r--r--  1 root wheel 12452892 Jun 30 08:17 /usr/local/lib/libhs.a
lrwxr-xr-x  1 root wheel       10 Jun 30 08:17 /usr/local/lib/libhs.so -> libhs.so.5
lrwxr-xr-x  1 root wheel       14 Jun 30 08:17 /usr/local/lib/libhs.so.5 -> libhs.so.5.4.0
-rwxr-xr-x  1 root wheel  4518952 Jun 30 08:17 /usr/local/lib/libhs.so.5.4.0

Your file dates are weird. June 30 for 2.7.2 files is too early. Mine show December 16 dates, which coincides with the day I updated this particular VM to 2.7.2 CE.

My file sizes agree 100% with those posted by @kiokoman. Your file dates of June 30 agree with the rollout of pfSense 2.7.0 CE. The 2.7.1 CE was released in November of this year.

You might want to remove the Suricata package from your VM, then run this command to be sure the Hyperscan library is also removed:

pkg info hyperscan

If anything other than something like "not installed" comes back, then manually remove Hyperscan with this command:

pkg delete hyperscan

You having an older library might be why you are getting the segfault instead of the same fatal error -1 termination that @kiokoman and most others are seeing.

Now reinstall Suricata and you should get the correct latest Hyperscan library.

masons

@bmeeks, I now have the same file sizes and dates. Would you like me to again load the debug package or do you have all that you need now?

bmeeks

@masons said in Suricata process dying due to hyperscan problem:

@bmeeks, I now have the same file sizes and dates. Would you like me to again load the debug package or do you have all that you need now?

It would be interesting to see if now instead of a segfault you get the fatal error termination that @kiokoman is seeing.

You do not have to install the debug package version for that test unless you just want to. I'm hoping maybe your segfault was an issue with the library compilation (being possibly from an older pfSense kernel build) and not a different manifestation of the same Hyperscan error.

So, just set the Pattern Matcher to Auto and attempt to start Suricata. If it dies immediately (or later), check the suricata.log file to see if you have the "Hyperscan returned fatal error -1" message. If you still get a Signal 11 segfault in the system log, then color me thoroughly flummoxed .

Negan

@bmeeks

Just had Suricata crash with this messag on my Netgate 8200:

Crash report begins. Anonymous machine information:

amd64
14.0-CURRENT
FreeBSD 14.0-CURRENT amd64 1400094 #1 plus-RELENG_23_09_1-n256200-3de1e293f3a: Wed Dec 6 21:00:32 UTC 2023 root@freebsd:/var/jenkins/workspace/pfSense-Plus-snapshots-23_09_1-main/obj/amd64/Obhu6gXB/var/jenkins/workspace/pfSense-Plus-snapshots-23_09_1

Crash report details:

PHP Errors:
[19-Dec-2023 13:50:29 Australia/Sydney] PHP Fatal error: Allowed memory size of 536870912 bytes exhausted (tried to allocate 896747264 bytes) in /usr/local/www/suricata/suricata_logs_browser.php on line 50

No FreeBSD crash data found.

sgnoc

@Negan I've had similar in other php files and these seem to be related to trying to do too much compared to the memory allocated for PHP. Were you trying to load a very large log file in Suricata Logs View? May be related to the specific interface and log type.

I'm no expert on this, so someone else may correct me, but maybe look at the log size and rotation settings for that interface and lower them so they cycle out more frequently, especially if it is a really busy interface?

Negan

@sgnoc
Your probably right, just never seen this after Suricata crashed before.....

bmeeks

@Negan said in Suricata process dying due to hyperscan problem:

@bmeeks

Just had Suricata crash with this messag on my Netgate 8200:

Crash report begins. Anonymous machine information:

amd64
14.0-CURRENT
FreeBSD 14.0-CURRENT amd64 1400094 #1 plus-RELENG_23_09_1-n256200-3de1e293f3a: Wed Dec 6 21:00:32 UTC 2023 root@freebsd:/var/jenkins/workspace/pfSense-Plus-snapshots-23_09_1-main/obj/amd64/Obhu6gXB/var/jenkins/workspace/pfSense-Plus-snapshots-23_09_1

Crash report details:

PHP Errors:
[19-Dec-2023 13:50:29 Australia/Sydney] PHP Fatal error: Allowed memory size of 536870912 bytes exhausted (tried to allocate 896747264 bytes) in /usr/local/www/suricata/suricata_logs_browser.php on line 50

No FreeBSD crash data found.

Please post this in a new thread so as not to pollute this one with completely unrelated information. Do you see anything in the error report you posted that says "Hyperscan"? If not, then posting in this thread that is titled "Hyperscan problem" breaks standard forum etiquette. Replies to a thread should stay on the topic of the thread.

With 248 posts, this thread is rapidly becoming too long, and burdening it with unrelated issues only makes that worse.

Negan

@bmeeks

Well this was in the log,

74327 - W#07] 2023-12-19 14:29:30 Error: spm-hs: Hyperscan returned fatal error -1.

And what I posted was there also, thought it might be related, which as you say it's not.

bmeeks

@Negan said in Suricata process dying due to hyperscan problem:

@bmeeks

Well this was in the log,

74327 - W#07] 2023-12-19 14:29:30 Error: spm-hs: Hyperscan returned fatal error -1.

And what I posted was there also, thought it might be related, which as you say it's not.

That error is definitely related, but the PHP one is not. This thread has gotten so large I've lost track of which user has posted something related previously and who has not.

Sorry if I sounded like the crusty old guy yelling "you kids get off my lawn!" .

Your PHP error is common to any action on pfSense that attempts to open a large text file for viewing in the PHP GUI. PHP just can't cope with large files as it must first load the entire file into memory and then stream it out line-by-line to a web client. You will need to view the file using command-line tools such as vi or transfer the file off to a PC and view with text editor apps there. The PHP process on pfSense has a fixed memory size that is somewhat independent of how much RAM you might actually have installed on the firewall. In other words, you will get that error no matter if you have 2GB of RAM or 64 GB of RAM installed.

Negan

@bmeeks

The thing is I was not looking at any files at the time, anyway, I just Deleted Sucicata as it's been of no benefit since 23.09. so I won't need to post here again, best of luck tracking down the error..

bmeeks

@Negan said in Suricata process dying due to hyperscan problem:

@bmeeks

The thing is I was not looking at any files at the time, anyway, I just Deleted Sucicata as it's been of no benefit since 23.09. so I need to post here again, best of luck tracking down the error..

You had to have been attempting to view one at some point. That's the only way that error can appear. The thing with the PHP errors, though, is that the Dashboard is the only place they will be shown. So if you tried to view a log two or three days ago, but never visited the Dashboard in the interim, then the next time you do open the Dashboard you will see the PHP error that was recorded in the past.

According to the error, someone attempted to view a log file from the LOGS VIEW tab at this date and time: 19-Dec-2023 13:50:29 Australia/Sydney.

Negan

@bmeeks
Well I only installed Sucicata again today and it was crashed and the PHP Error was there, anyway, thanks for helping....

kiokoman

@masons
i suspected you had a different version of hyperscan because i had that same crash when using hyperscan 5.4.2 instead of 5.4.0
now that you have corrected the situation I expect that you no longer have the crash/core dump but only hyperscan that fails like me

bmeeks

@kiokoman and @masons:
The upstream Suricata developer team took a look at your gdb back trace reports and has asked me to prepare a new debug Suricata package with the Address Sanitizer option enabled and let you run that for a while. That option performs a very detailed memory use analysis at runtime and can print more detailed debugging messages.

I'm working on creating that build now and will test it on my system first to be sure it functions. Once I get everything ready, I will post a link to it back here in this thread.