StamusNetworks / SELKS

A Suricata based IDS/IPS/NSM distro
https://www.stamus-networks.com/open-source/#selks
GNU General Public License v3.0
1.48k stars 285 forks source link

Suricata fails with hyperscan error #285

Closed ssvinarev closed 3 years ago

ssvinarev commented 3 years ago

Hi!

Suricata sometimes fails with this error in suricata.log: _ - [ERRCODE: SC_ERRFATAL(171)] - Hyperscan returned error -1

At the same time in messages: device enp1s0f0 left promiscuous mode device enp1s0f1 left promiscuous mode

It's af_packet in IPS mode, inline. Error of course terminates the channel, until hardware WDT on NIC switches ports to bypass.

suricata --build-info This is Suricata version 6.0.0 RELEASE Features: NFQ PCAP_SET_BUFF AF_PACKET HAVE_PACKET_FANOUT LIBCAP_NG LIBNET1.1 HAVE_HTP_URI_NORMALIZE_HOOK PCRE_JIT HAVE_NSS HAVE_LUA HAVE_LUAJIT HAVE_LIBJANSSON TLS TLS_C11 MAGIC RUST SIMD support: none Atomic intrinsics: 1 2 4 8 byte(s) 64-bits, Little-endian architecture GCC version 8.3.0, C version 201112 compiled with _FORTIFY_SOURCE=2 L1 cache line size (CLS)=64 thread local storage method: _Thread_local compiled with LibHTP v0.5.35, linked against LibHTP v0.5.35

Suricata Configuration: AF_PACKET support: yes eBPF support: no XDP support: no PF_RING support: no NFQueue support: yes NFLOG support: no IPFW support: no Netmap support: no DAG enabled: no Napatech enabled: no WinDivert enabled: no

Unix socket enabled: yes Detection enabled: yes

Libmagic support: yes libnss support: yes libnspr support: yes libjansson support: yes hiredis support: yes hiredis async with libevent: no Prelude support: no PCRE jit: yes LUA support: yes, through luajit libluajit: yes GeoIP2 support: yes Non-bundled htp: yes Old barnyard2 support: Hyperscan support: yes Libnet support: yes liblz4 support: yes

Rust support: yes Rust strict mode: no Rust compiler path: /root/.cargo/bin/rustc Rust compiler version: rustc 1.47.0 (18bf6b4f0 2020-10-07) Cargo path: /root/.cargo/bin/cargo Cargo version: cargo 1.47.0 (f3c7e066a 2020-08-28) Cargo vendor: yes

Python support: yes Python path: /usr/bin/python3 Python distutils yes Python yaml yes Install suricatactl: yes Install suricatasc: yes Install suricata-update: yes

Profiling enabled: no Profiling locks enabled: no

Plugin support (experimental): yes

Development settings: Coccinelle / spatch: yes Unit tests enabled: no Debug output enabled: no Debug validation enabled: no

Generic build parameters: Installation prefix: /usr Configuration directory: /etc/suricata/ Log directory: /var/log/suricata/

--prefix /usr --sysconfdir /etc --localstatedir /var --datarootdir /usr/share

Host: x86_64-pc-linux-gnu Compiler: gcc (exec name) / g++ (real) GCC Protect enabled: yes GCC march native enabled: no GCC Profile enabled: no Position Independent Executable enabled: yes CFLAGS -g -O2 -fdebug-prefix-map=/STAMUS/SELKS6/Suricata/suricata-2020100901=. -fstack-protector-strong -Wformat -Werror=format-security -std=c11 -I${srcdir}/../rust/gen -I${srcdir}/../rust/dist PCAP_CFLAGS -I/usr/include SECCFLAGS -fstack-protector -D_FORTIFY_SOURCE=2 -Wformat -Wformat-security

Any ideas how to fix? Thanks!

pevma commented 3 years ago

Is it reproducible somehow or it happens only randomly ? Maybe you could try the selks-upgrade_stamus upgrade routine and try the latest Suricata see if it has the same behavior?

-- Regards, Peter Manev

On 24 Dec 2020, at 10:34, ssvinarev notifications@github.com wrote:

 Hi!

Suricata sometimes fails with this error in suricata.log:

  • [ERRCODE: SC_ERR_FATAL(171)] - Hyperscan returned error -1

At the same time in messages: device enp1s0f0 left promiscuous mode device enp1s0f1 left promiscuous mode

It's af_packet in IPS mode, inline. Error of course terminates the channel, until hardware WDT on NIC switches ports to bypass.

suricata --build-info This is Suricata version 6.0.0 RELEASE Features: NFQ PCAP_SET_BUFF AF_PACKET HAVE_PACKET_FANOUT LIBCAP_NG LIBNET1.1 HAVE_HTP_URI_NORMALIZE_HOOK PCRE_JIT HAVE_NSS HAVE_LUA HAVE_LUAJIT HAVE_LIBJANSSON TLS TLS_C11 MAGIC RUST SIMD support: none Atomic intrinsics: 1 2 4 8 byte(s) 64-bits, Little-endian architecture GCC version 8.3.0, C version 201112 compiled with _FORTIFY_SOURCE=2 L1 cache line size (CLS)=64 thread local storage method: _Thread_local compiled with LibHTP v0.5.35, linked against LibHTP v0.5.35

Suricata Configuration: AF_PACKET support: yes eBPF support: no XDP support: no PF_RING support: no NFQueue support: yes NFLOG support: no IPFW support: no Netmap support: no DAG enabled: no Napatech enabled: no WinDivert enabled: no

Unix socket enabled: yes Detection enabled: yes

Libmagic support: yes libnss support: yes libnspr support: yes libjansson support: yes hiredis support: yes hiredis async with libevent: no Prelude support: no PCRE jit: yes LUA support: yes, through luajit libluajit: yes GeoIP2 support: yes Non-bundled htp: yes Old barnyard2 support: Hyperscan support: yes Libnet support: yes liblz4 support: yes

Rust support: yes Rust strict mode: no Rust compiler path: /root/.cargo/bin/rustc Rust compiler version: rustc 1.47.0 (18bf6b4f0 2020-10-07) Cargo path: /root/.cargo/bin/cargo Cargo version: cargo 1.47.0 (f3c7e066a 2020-08-28) Cargo vendor: yes

Python support: yes Python path: /usr/bin/python3 Python distutils yes Python yaml yes Install suricatactl: yes Install suricatasc: yes Install suricata-update: yes

Profiling enabled: no Profiling locks enabled: no

Plugin support (experimental): yes

Development settings: Coccinelle / spatch: yes Unit tests enabled: no Debug output enabled: no Debug validation enabled: no

Generic build parameters: Installation prefix: /usr Configuration directory: /etc/suricata/ Log directory: /var/log/suricata/

--prefix /usr --sysconfdir /etc --localstatedir /var --datarootdir /usr/share

Host: x86_64-pc-linux-gnu Compiler: gcc (exec name) / g++ (real) GCC Protect enabled: yes GCC march native enabled: no GCC Profile enabled: no Position Independent Executable enabled: yes CFLAGS -g -O2 -fdebug-prefix-map=/STAMUS/SELKS6/Suricata/suricata-2020100901=. -fstack-protector-strong -Wformat -Werror=format-security -std=c11 -I${srcdir}/../rust/gen -I${srcdir}/../rust/dist PCAP_CFLAGS -I/usr/include SECCFLAGS -fstack-protector -D_FORTIFY_SOURCE=2 -Wformat -Wformat-security

Any ideas how to fix? Thanks!

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or unsubscribe.

ssvinarev commented 3 years ago

Tried to manually reproduce, but no success. Seems what it's random. The only thing I can say, that this error most often happens when a user is actively working with EveBox and exploring events. It may be the result of some event discovering activity.

Thought about upgrade. Is there any changelog to check changes from my current 2020100901-0stamus0 to available 2020121901-0stamus0 ?

pevma commented 3 years ago

It doesn’t really seem related - EveBox queries Elastic search -maybe resource contention ?

About the change log - yep that would be great to add indeed -I will work on it. However a quick check would be all commits on suricata gitmaster (github) between those two dates (the suri packages).

-- Regards, Peter Manev

On 24 Dec 2020, at 12:29, ssvinarev notifications@github.com wrote:

 Tried to manually reproduce, but no success. Seems what it's random. The only thing I can say, that this error most often happens when a user is actively working with EveBox and exploring events. It may be the result of some event discovering activity.

Thought about upgrade. Is there any changelog to check changes from my current 2020100901-0stamus0 to available 2020121901-0stamus0 ?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

ssvinarev commented 3 years ago

Sure not related. Resources contention - maybe. But checked monitoring metrics just before failures - nothing unusual.

I will check commits on suricata github.

About update. Can I manually update: elasticsearch 7.10.0 -> 7.10.1 kibana 7.10.0 -> 7.10.1 kibana-dashboards-stamus 2020042401 -> 2020122001 libhtp2 0.5.35-0stamus0 -> 0.5.36-0stamus0 logstash 7.10.0-1 -> 7.10.1-1 selks-scripts-stamus 2020040801 -> 2020121401 suricata 2020100901-0stamus0 -> 2020121901-0stamus0 Instead of selks-upgrade_stamus?

pevma commented 3 years ago

Yes you can, I think it should be regular “apt-update && apt install suricata” for example.

-- Regards, Peter Manev

On 24 Dec 2020, at 20:19, ssvinarev notifications@github.com wrote:

 Sure not related. Resources contention - maybe. But checked monitoring metrics just before failures - nothing unusual.

I will check commits on suricata github.

About update. Can I manually update: elasticsearch 7.10.0 -> 7.10.1 kibana 7.10.0 -> 7.10.1 kibana-dashboards-stamus 2020042401 -> 2020122001 libhtp2 0.5.35-0stamus0 -> 0.5.36-0stamus0 logstash 7.10.0-1 -> 7.10.1-1 selks-scripts-stamus 2020040801 -> 2020121401 suricata 2020100901-0stamus0 -> 2020121901-0stamus0 Instead of selks-upgrade_stamus?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

ssvinarev commented 3 years ago

Hi!

Updated to latest versions. Now suricata version is 7.0.0-dev (f8fef0dd0 2021-01-05). Everything works fine, but sometimes suricata still fails with the same error: _(util-mpm-hs.c:952) (SCHSSearch) -- [ERRCODE: SC_ERRFATAL(171)] - Hyperscan returned error -1

The message is more verbose now. It points to: https://github.com/OISF/suricata/blob/master/src/util-mpm-hs.c#L952

Looks like hs_scan() got an invalid input caused that error.

Any ideas how to troubleshoot it? May be disable some protocol parsers?

pevma commented 3 years ago

I just pushed anew pkg (latest git master) that includes some fixes too. Not sure if it will fix it but worth a try.

Best is if you can see if it is reproducible?

ssvinarev commented 3 years ago

Updated. Now suricata version is 7.0.0-dev (3a8ba663a 2021-01-13) And already got the same error twice: _(util-mpm-hs.c:952) (SCHSSearch) -- [ERRCODE: SC_ERRFATAL(171)] - Hyperscan returned error -1

May be there is a way to trace "problem" calls of hs_scan() somehow?

Or, as a workaround, I can switch to mpm-algo: ac/ac-bs/ac-ks and spm-algo: bm instead of "hs"

Which of ac/dc-bs/ac-ks is "better" for mpm-algo?

pevma commented 3 years ago

I suggest ac-ks. To trace it i think you need to install the dbg pkg and try that way - if it is often reproducible?

ssvinarev commented 3 years ago

Hi!

Switched to ac-ks. Now got more unclear situation. Suricata still fails sometimes, but now without any error in logs at all.. suricata.service simply changes its state to active (exited).

As the result in messages: W#01-enp1s0f0[19947]: segfault at 0 ip 0000556ad1480658 sp 00007f0f5a97b330 error 4 in suricata[556ad134e000+3b6000] Jan 18 14:50:31 SELKS kernel: [250812.669621] Code: 45 c8 31 c0 48 8d 42 0f 48 c1 e8 04 48 c1 e0 04 48 29 c4 48 89 e7 48 89 65 a8 e8 8b f0 ec ff 4c 8b 55 b8 4c 8b b3 08 01 00 00 <41> 0f b6 02 44 0f b6 64 03 08 41 83 fd 07 0f 86 04 01 00 00 41 f6 device enp1s0f1 left promiscuous mode device enp1s0f0 left promiscuous mode

Any ideas?

pevma commented 3 years ago

Ok - I think we can try to narrow it down Is it possible to install the suricata-dbg pkg and run suricata again- this should give useful debugging information when it happens next.

Thank you

-- Regards, Peter Manev

On 18 Jan 2021, at 14:39, ssvinarev notifications@github.com wrote:

 Hi!

Switched to ac-ks. Now got more unclear situation. Suricata still fails sometimes, but now without any error in logs at all.. suricata.service simply changes its state to active (exited).

As the result in messages: W#01-enp1s0f0[19947]: segfault at 0 ip 0000556ad1480658 sp 00007f0f5a97b330 error 4 in suricata[556ad134e000+3b6000] Jan 18 14:50:31 SELKS kernel: [250812.669621] Code: 45 c8 31 c0 48 8d 42 0f 48 c1 e8 04 48 c1 e0 04 48 29 c4 48 89 e7 48 89 65 a8 e8 8b f0 ec ff 4c 8b 55 b8 4c 8b b3 08 01 00 00 <41> 0f b6 02 44 0f b6 64 03 08 41 83 fd 07 0f 86 04 01 00 00 41 f6 device enp1s0f1 left promiscuous mode device enp1s0f0 left promiscuous mode

Any ideas?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

ssvinarev commented 3 years ago

Hi!

Installed suricata-dbg 2021011401-0stamus0 Please help, what to do next? Recompile with --enable-debug ? Enable logging.default-log-level: debug ? Is there any guide how to collect debug info related to SELKS ?

Current build-info is: This is Suricata version 7.0.0-dev (3a8ba663a 2021-01-13) Features: NFQ PCAP_SET_BUFF AF_PACKET HAVE_PACKET_FANOUT LIBCAP_NG LIBNET1.1 HAVE_HTP_URI_NORMALIZE_HOOK PCRE_JIT HAVE_NSS HAVE_LUA HAVE_LUAJIT HAVE_LIBJANSSON TLS TLS_C11 MAGIC RUST SIMD support: none Atomic intrinsics: 1 2 4 8 byte(s) 64-bits, Little-endian architecture GCC version 8.3.0, C version 201112 compiled with _FORTIFY_SOURCE=2 L1 cache line size (CLS)=64 thread local storage method: _Thread_local compiled with LibHTP v0.5.36, linked against LibHTP v0.5.36

Suricata Configuration: AF_PACKET support: yes eBPF support: no XDP support: no PF_RING support: no NFQueue support: yes NFLOG support: no IPFW support: no Netmap support: no DAG enabled: no Napatech enabled: no WinDivert enabled: no

Unix socket enabled: yes Detection enabled: yes

Libmagic support: yes libjansson support: yes hiredis support: yes hiredis async with libevent: no Prelude support: no PCRE jit: yes LUA support: yes, through luajit libluajit: yes GeoIP2 support: yes Non-bundled htp: yes Hyperscan support: yes Libnet support: yes liblz4 support: yes

Rust support: yes Rust strict mode: no Rust compiler path: /root/.cargo/bin/rustc Rust compiler version: rustc 1.49.0 (e1884a8e3 2020-12-29) Cargo path: /root/.cargo/bin/cargo Cargo version: cargo 1.49.0 (d00d64df9 2020-12-05) Cargo vendor: yes

Python support: yes Python path: /usr/bin/python3 Python distutils yes Python yaml yes Install suricatactl: yes Install suricatasc: yes Install suricata-update: yes

Profiling enabled: no Profiling locks enabled: no

Plugin support (experimental): yes

Development settings: Coccinelle / spatch: yes Unit tests enabled: no Debug output enabled: no Debug validation enabled: no

Generic build parameters: Installation prefix: /usr Configuration directory: /etc/suricata/ Log directory: /var/log/suricata/

--prefix /usr --sysconfdir /etc --localstatedir /var --datarootdir /usr/share

Host: x86_64-pc-linux-gnu Compiler: gcc (exec name) / g++ (real) GCC Protect enabled: yes GCC march native enabled: no GCC Profile enabled: no Position Independent Executable enabled: yes CFLAGS -g -O2 -fdebug-prefix-map=/STAMUS/SELKS6/Suricata/suricata-2021011401=. -fstack-protector-strong -Wformat -Werror=format-security -std=c11 -I${srcdir}/../rust/gen -I${srcdir}/../rust/dist PCAP_CFLAGS -I/usr/include SECCFLAGS -fstack-protector -D_FORTIFY_SOURCE=2 -Wformat -Wformat-security

Thanks!

pevma commented 3 years ago

Think the best will be to remove any core files (/var/log/suricata/core) And (re)start suricata again.

ssvinarev commented 3 years ago

Done. Deleted /var/log/suricata/core/core file, nothing more. Is thats all? Now wait for an error and check logs for more verbose output?

pevma commented 3 years ago

Yep. Then if we get a new core - we can dig into the debug info.

ssvinarev commented 3 years ago

Hi!

Caught that error again. Suricata.service changed state to active (exited). But there are no new messages in /var/log/suricata/suricata.log at the crash moment. Looks like, nothing changed in a context of more verbose output.

What could be wrong?

pevma commented 3 years ago

Do you have a core in /var/log/suricata/core ?

ssvinarev commented 3 years ago

Yes. It's binary, created at the crash moment.

pevma commented 3 years ago

Can you try

gdb /usr/bin/suricata /var/log/suricata/core 
(gdb) set logging on
(gdb) thread apply all bt
ssvinarev commented 3 years ago

Ok, of course:

# systemctl status suricata.service
● suricata.service - LSB: Next Generation IDS/IPS
   Loaded: loaded (/etc/init.d/suricata; generated)
   Active: active (exited) since Fri 2021-01-22 02:00:36 MSK; 13h ago
     Docs: man:systemd-sysv-generator(8)
  Process: 27088 ExecStart=/etc/init.d/suricata start (code=exited, status=0/SUCCESS)

Jan 22 02:00:36 SELKS systemd[1]: Starting LSB: Next Generation IDS/IPS...
Jan 22 02:00:36 SELKS suricata[27088]: Starting suricata in IDS (af-packet) mode... done.
Jan 22 02:00:36 SELKS systemd[1]: Started LSB: Next Generation IDS/IPS.
# gdb /usr/bin/suricata /var/log/suricata/core/core
GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/suricata...Reading symbols from /usr/lib/debug/.build-id/58/346f7cfd5262bc2dccbbd152659197b2e6c512.debug...done.
done.

warning: core file may not match specified executable file.
[New LWP 27105]
[New LWP 27111]
[New LWP 27110]
[New LWP 27107]
[New LWP 27106]
[New LWP 27108]
[New LWP 27109]
[New LWP 27094]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/bin/suricata -c /etc/suricata/suricata.yaml --pidfile /var/run/suricata.pi'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  SCACTileSearchTiny32 (ctx=0x557696e99ca0, mpm_thread_ctx=<optimized out>, pmq=0x7f15242d12c0, buf=0x0, buflen=8) at util-mpm-ac-ks-small.c:46
46      util-mpm-ac-ks-small.c: No such file or directory.
[Current thread is 1 (Thread 0x7f155fe49700 (LWP 27105))]
(gdb)
(gdb) set logging on
Copying output to gdb.txt.
(gdb) thread apply all bt

Thread 8 (Thread 0x7f1561752b00 (LWP 27094)):
#0  0x00007f1561baa720 in __GI___nanosleep (requested_time=requested_time@entry=0x7ffd33997340, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f1561bd5874 in usleep (useconds=useconds@entry=10000) at ../sysdeps/posix/usleep.c:32
#2  0x0000557696233b27 in SuricataMainLoop (suri=<optimized out>) at suricata.c:2644
#3  SuricataMain (argc=<optimized out>, argv=<optimized out>) at suricata.c:2805
#4  0x00007f1561b0809b in __libc_start_main (main=0x557696136950 <main>, argc=9, argv=0x7ffd33997498, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd33997488)
    at ../csu/libc-start.c:308
#5  0x000055769613698a in _start ()

Thread 7 (Thread 0x7f155d30b700 (LWP 27109)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f155d30aad0, expected=0, futex_word=0x5576ce21cfc8) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  __pthread_cond_wait_common (abstime=0x7f155d30aad0, mutex=0x5576a124a760, cond=0x5576ce21cfa0) at pthread_cond_wait.c:539
#2  __pthread_cond_timedwait (cond=0x5576ce21cfa0, mutex=0x5576a124a760, abstime=abstime@entry=0x7f155d30aad0) at pthread_cond_wait.c:667
#3  0x00005576961679cc in StatsWakeupThread (arg=0x5576a4081250) at counters.c:487
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 6 (Thread 0x7f155db0c700 (LWP 27108)):
#0  0x00007f1561baa720 in __GI___nanosleep (requested_time=requested_time@entry=0x7f155db0ba10, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f1561bd5874 in usleep (useconds=useconds@entry=100) at ../sysdeps/posix/usleep.c:32
#2  0x00005576961def16 in FlowRecycler (th_v=0x5576a2ea3d40, thread_data=0x7f1508000b20) at flow-manager.c:1210
#3  0x00005576962373e2 in TmThreadsManagement (td=0x5576a2ea3d40) at tm-threads.c:541
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 5 (Thread 0x7f155f0ab700 (LWP 27106)):
#0  0x00007f1561bd2819 in __GI___poll (fds=fds@entry=0x7f155f0aa9d0, nfds=nfds@entry=1, timeout=timeout@entry=100) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x00005576962195ad in poll (__timeout=100, __nfds=1, __fds=0x7f155f0aa9d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  ReceiveAFPLoop (tv=0x5576b21e13e0, data=0x7f151c274b20, slot=<optimized out>) at source-af-packet.c:1544
#3  0x000055769623768c in TmThreadsSlotPktAcqLoop (td=0x5576b21e13e0) at tm-threads.c:312
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 4 (Thread 0x7f155e30d700 (LWP 27107)):
#0  0x00007f1561baa720 in __GI___nanosleep (requested_time=requested_time@entry=0x7f155e30c9b0, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f1561bd5874 in usleep (useconds=useconds@entry=100) at ../sysdeps/posix/usleep.c:32
#2  0x00005576961df8a3 in FlowManager (th_v=0x5576a2e7cde0, thread_data=0x7f1520000b20) at flow-manager.c:1014
#3  0x00005576962373e2 in TmThreadsManagement (td=0x5576a2e7cde0) at tm-threads.c:541
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 3 (Thread 0x7f155cb0a700 (LWP 27110)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f155cb09ad0, expected=0, futex_word=0x5576ce26b5c8) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  __pthread_cond_wait_common (abstime=0x7f155cb09ad0, mutex=0x5576a12bb5c0, cond=0x5576ce26b5a0) at pthread_cond_wait.c:539
#2  __pthread_cond_timedwait (cond=0x5576ce26b5a0, mutex=0x5576a12bb5c0, abstime=abstime@entry=0x7f155cb09ad0) at pthread_cond_wait.c:667
#3  0x0000557696168013 in StatsMgmtThread (arg=<optimized out>) at counters.c:415
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 2 (Thread 0x7f155c309700 (LWP 27111)):
#0  0x00007f1561bd5037 in __GI___select (nfds=7, readfds=readfds@entry=0x7f155c308850, writefds=writefds@entry=0x0, exceptfds=exceptfds@entry=0x0, timeout=timeout@entry=0x7f155c308840)
    at ../sysdeps/unix/sysv/linux/select.c:41
#1  0x000055769623ab15 in UnixMain (this=0x557696656f20 <command>) at unix-manager.c:650
#2  UnixManager (th_v=0x55769b359bb0, thread_data=<optimized out>) at unix-manager.c:1125
#3  0x00005576962373e2 in TmThreadsManagement (td=0x55769b359bb0) at tm-threads.c:541
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
--Type <RET> for more, q to quit, c to continue without paging--

Thread 1 (Thread 0x7f155fe49700 (LWP 27105)):
#0  SCACTileSearchTiny32 (ctx=0x557696e99ca0, mpm_thread_ctx=<optimized out>, pmq=0x7f15242d12c0, buf=0x0, buflen=8) at util-mpm-ac-ks-small.c:46
#1  0x000055769613af7f in PMGetProtoInspect (rflow=0x7f155fe48527, pm_results=0x7f155fe48440, direction=41 ')', buflen=397, buf=0x0, f=0x7f15203aa6a0, mpm_tctx=<optimized out>,
    pm_ctx=0x557696647fe8 <alpd_ctx+72>, tctx=0x7f15242d12c0) at app-layer-detect-proto.c:275
#2  AppLayerProtoDetectPMGetProto (rflow=0x7f155fe48527, pm_results=0x7f155fe48440, direction=41 ')', buflen=397, buf=0x0, f=0x7f15203aa6a0, tctx=0x7f15242d12c0) at app-layer-detect-proto.c:342
#3  AppLayerProtoDetectGetProto (tctx=0x7f15242d12c0, f=f@entry=0x7f15203aa6a0, buf=buf@entry=0x0, buflen=buflen@entry=397, ipproto=ipproto@entry=6 '\006', direction=direction@entry=41 ')',
    reverse_flow=0x7f155fe48527) at app-layer-detect-proto.c:1551
#4  0x0000557696138df4 in TCPProtoDetect (tv=0x5576b75b1fa0, ra_ctx=0x7f15242d1270, app_tctx=app_tctx@entry=0x7f15242d12a0, p=p@entry=0x7f1524274150, f=f@entry=0x7f15203aa6a0,
    ssn=ssn@entry=0x7f151c3321b0, stream=0x7f155fe48648, data=0x0, data_len=397, flags=41 ')') at app-layer.c:336
#5  0x0000557696139921 in AppLayerHandleTCPData (tv=tv@entry=0x5576b75b1fa0, ra_ctx=ra_ctx@entry=0x7f15242d1270, p=p@entry=0x7f1524274150, f=0x7f15203aa6a0, ssn=ssn@entry=0x7f151c3321b0,
    stream=stream@entry=0x7f155fe48648, data=0x0, data_len=397, flags=41 ')') at app-layer.c:642
#6  0x000055769622dbb7 in ReassembleUpdateAppLayer (dir=UPDATE_DIR_PACKET, p=0x7f1524274150, stream=0x7f155fe48648, ssn=0x7f151c3321b0, ra_ctx=0x7f15242d1270, tv=0x5576b75b1fa0)
    at stream-tcp-reassemble.c:1175
#7  StreamTcpReassembleAppLayer (tv=tv@entry=0x5576b75b1fa0, ra_ctx=ra_ctx@entry=0x7f15242d1270, ssn=ssn@entry=0x7f151c3321b0, stream=<optimized out>, stream@entry=0x7f151c3321c0,
    p=p@entry=0x7f1524274150, dir=dir@entry=UPDATE_DIR_PACKET) at stream-tcp-reassemble.c:1238
#8  0x000055769622eb23 in StreamTcpReassembleHandleSegment (tv=tv@entry=0x5576b75b1fa0, ra_ctx=0x7f15242d1270, ssn=ssn@entry=0x7f151c3321b0, stream=0x7f151c3321c0, p=p@entry=0x7f1524274150,
    pq=pq@entry=0x7f15242d0f68) at stream-tcp-reassemble.c:1900
#9  0x000055769622392e in HandleEstablishedPacketToClient (stt=<optimized out>, pq=<optimized out>, p=<optimized out>, ssn=<optimized out>, tv=<optimized out>) at stream-tcp.c:2318
#10 StreamTcpPacketStateEstablished (tv=0x5576b75b1fa0, p=0x7f1524274150, stt=stt@entry=0x7f15242d0f60, ssn=0x7f151c3321b0, pq=0x7f15242d0f68) at stream-tcp.c:2702
#11 0x0000557696228da8 in StreamTcpStateDispatch (tv=0x5576b75b1fa0, p=0x7f1524274150, stt=0x7f15242d0f60, ssn=0x7f151c3321b0, pq=0x7f15242d0f68, state=<optimized out>) at stream-tcp.c:4703
#12 0x000055769622a682 in StreamTcpPacket (tv=0x5576b75b1fa0, p=0x7f1524274150, stt=0x7f15242d0f60, pq=0x7f15242aeb40) at stream-tcp.c:4889
#13 0x000055769622ae24 in StreamTcp (tv=tv@entry=0x5576b75b1fa0, p=p@entry=0x7f1524274150, data=<optimized out>, pq=pq@entry=0x7f15242aeb40) at stream-tcp.c:5225
#14 0x00005576961e2a2f in FlowWorkerStreamTCPUpdate (detect_thread=0x7f15243a3520, p=0x7f1524274150, fw=0x7f15242aeb10, tv=0x5576b75b1fa0) at flow-worker.c:524
#15 FlowWorker (tv=0x5576b75b1fa0, p=0x7f1524274150, data=0x7f15242aeb10) at flow-worker.c:524
#16 0x0000557696235fa2 in TmThreadsSlotVarRun (tv=tv@entry=0x5576b75b1fa0, p=p@entry=0x7f1524274150, slot=<optimized out>) at tm-threads.c:117
#17 0x0000557696219102 in TmThreadsSlotProcessPkt (p=0x7f1524274150, s=<optimized out>, tv=0x5576b75b1fa0) at tm-threads.h:192
#18 AFPReadFromRing (ptv=ptv@entry=0x7f1524274b20) at source-af-packet.c:1011
#19 0x00005576962196c9 in ReceiveAFPLoop (tv=0x5576b75b1fa0, data=0x7f1524274b20, slot=<optimized out>) at source-af-packet.c:1571
#20 0x000055769623768c in TmThreadsSlotPktAcqLoop (td=0x5576b75b1fa0) at tm-threads.c:312
#21 0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#22 0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
pevma commented 3 years ago

Can you please also post suricata --build-info ?

ssvinarev commented 3 years ago

It's the same now https://github.com/StamusNetworks/SELKS/issues/285#issuecomment-762831052

pevma commented 3 years ago

Thank you for sharing the debug info. I've opened a corresponding issue here https://redmine.openinfosecfoundation.org/issues/4273

Question when you had the hyperscan error - it was just the error no seg/core dumps right ? I think in that case it is better to switch back to mpm-algo: hs

ssvinarev commented 3 years ago

Hi! Yes, just the error with no dumps.

I can switch back to hs algo, make dump and share it here after next error. Hope this helps.

ssvinarev commented 3 years ago

I see, there are two new packages available:

Are there any fixes here related to current issue?

ssvinarev commented 3 years ago

Deleted /var/log/suricata/core/core Switched back to hs. And there is hs error back again:

[14852] 25/1/2021 -- 14:21:49 - (util-mpm-hs.c:952) (SCHSSearch) -- [ERRCODE: SC_ERR_FATAL(171)] - Hyperscan returned error -1

Didn't update to 2021012201-0stamus0 yet, so build-info is the same as before. No core file in /var/log/suricata/core, so no dump.

pevma commented 3 years ago

suricata 2021012201-0stamus0 is the latest. Upon the error above - does Suricata continue to operate or?

ssvinarev commented 3 years ago

No, suricata fails upon the error: suricata.service goes to active (exited), as it was before. Today I am going to update to 2021012201-0stamus0 and see if it changes something.

pevma commented 3 years ago

ok - what you might want to do is install the dbg package again and run it with HS so when it exits we will have the core and the debug info again (last time we run it with ac-ks, so maybe we will have some luck now with hs).

ssvinarev commented 3 years ago

Done. Installed suricata 2021012201-0stamus0 and suricata-dbg 2021012201-0stamus0. Deleted old core file. It's running now in hs. Waiting for the error...

ssvinarev commented 3 years ago

The same again: suricata.service - LSB: Next Generation IDS/IPS Loaded: loaded (/etc/init.d/suricata; generated) Active: active (exited) and in log: (util-mpm-hs.c:952) <Error> (SCHSSearch) -- [ERRCODE: SC_ERR_FATAL(171)] - Hyperscan returned error -1

And nothing new in /var/log/suricata/core/core since service started last time, so there is no usefull debug info.

Is there any other way to collect the dump working with HS algo?

ssvinarev commented 3 years ago

Going to try other possible algos:

pevma commented 3 years ago

Yep makes sense - please let us know how it goes !

-- Regards, Peter Manev

On 30 Jan 2021, at 11:52, ssvinarev notifications@github.com wrote:

 Going to try other possible algos:

ac-bs ac — You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

ssvinarev commented 3 years ago

Hi!

Caught that error again.

New dump in ac-bs mode. Symptoms are the same. Suricata.service changed state to active (exited). Nothing in suricata.log at crash.

Thread 8 (Thread 0x7f1561752b00 (LWP 27094)):
#0  0x00007f1561baa720 in __GI___nanosleep (requested_time=requested_time@entry=0x7ffd33997340, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f1561bd5874 in usleep (useconds=useconds@entry=10000) at ../sysdeps/posix/usleep.c:32
#2  0x0000557696233b27 in SuricataMainLoop (suri=<optimized out>) at suricata.c:2644
#3  SuricataMain (argc=<optimized out>, argv=<optimized out>) at suricata.c:2805
#4  0x00007f1561b0809b in __libc_start_main (main=0x557696136950 <main>, argc=9, argv=0x7ffd33997498, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffd33997488)
    at ../csu/libc-start.c:308
#5  0x000055769613698a in _start ()

Thread 7 (Thread 0x7f155d30b700 (LWP 27109)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f155d30aad0, expected=0, futex_word=0x5576ce21cfc8) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  __pthread_cond_wait_common (abstime=0x7f155d30aad0, mutex=0x5576a124a760, cond=0x5576ce21cfa0) at pthread_cond_wait.c:539
#2  __pthread_cond_timedwait (cond=0x5576ce21cfa0, mutex=0x5576a124a760, abstime=abstime@entry=0x7f155d30aad0) at pthread_cond_wait.c:667
#3  0x00005576961679cc in StatsWakeupThread (arg=0x5576a4081250) at counters.c:487
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 6 (Thread 0x7f155db0c700 (LWP 27108)):
#0  0x00007f1561baa720 in __GI___nanosleep (requested_time=requested_time@entry=0x7f155db0ba10, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f1561bd5874 in usleep (useconds=useconds@entry=100) at ../sysdeps/posix/usleep.c:32
#2  0x00005576961def16 in FlowRecycler (th_v=0x5576a2ea3d40, thread_data=0x7f1508000b20) at flow-manager.c:1210
#3  0x00005576962373e2 in TmThreadsManagement (td=0x5576a2ea3d40) at tm-threads.c:541
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 5 (Thread 0x7f155f0ab700 (LWP 27106)):
#0  0x00007f1561bd2819 in __GI___poll (fds=fds@entry=0x7f155f0aa9d0, nfds=nfds@entry=1, timeout=timeout@entry=100) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x00005576962195ad in poll (__timeout=100, __nfds=1, __fds=0x7f155f0aa9d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  ReceiveAFPLoop (tv=0x5576b21e13e0, data=0x7f151c274b20, slot=<optimized out>) at source-af-packet.c:1544
#3  0x000055769623768c in TmThreadsSlotPktAcqLoop (td=0x5576b21e13e0) at tm-threads.c:312
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 4 (Thread 0x7f155e30d700 (LWP 27107)):
#0  0x00007f1561baa720 in __GI___nanosleep (requested_time=requested_time@entry=0x7f155e30c9b0, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f1561bd5874 in usleep (useconds=useconds@entry=100) at ../sysdeps/posix/usleep.c:32
#2  0x00005576961df8a3 in FlowManager (th_v=0x5576a2e7cde0, thread_data=0x7f1520000b20) at flow-manager.c:1014
#3  0x00005576962373e2 in TmThreadsManagement (td=0x5576a2e7cde0) at tm-threads.c:541
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 3 (Thread 0x7f155cb0a700 (LWP 27110)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f155cb09ad0, expected=0, futex_word=0x5576ce26b5c8) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  __pthread_cond_wait_common (abstime=0x7f155cb09ad0, mutex=0x5576a12bb5c0, cond=0x5576ce26b5a0) at pthread_cond_wait.c:539
#2  __pthread_cond_timedwait (cond=0x5576ce26b5a0, mutex=0x5576a12bb5c0, abstime=abstime@entry=0x7f155cb09ad0) at pthread_cond_wait.c:667
#3  0x0000557696168013 in StatsMgmtThread (arg=<optimized out>) at counters.c:415
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 2 (Thread 0x7f155c309700 (LWP 27111)):
#0  0x00007f1561bd5037 in __GI___select (nfds=7, readfds=readfds@entry=0x7f155c308850, writefds=writefds@entry=0x0, exceptfds=exceptfds@entry=0x0, timeout=timeout@entry=0x7f155c308840)
    at ../sysdeps/unix/sysv/linux/select.c:41
#1  0x000055769623ab15 in UnixMain (this=0x557696656f20 <command>) at unix-manager.c:650
#2  UnixManager (th_v=0x55769b359bb0, thread_data=<optimized out>) at unix-manager.c:1125
#3  0x00005576962373e2 in TmThreadsManagement (td=0x55769b359bb0) at tm-threads.c:541
#4  0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 1 (Thread 0x7f155fe49700 (LWP 27105)):
#0  SCACTileSearchTiny32 (ctx=0x557696e99ca0, mpm_thread_ctx=<optimized out>, pmq=0x7f15242d12c0, buf=0x0, buflen=8) at util-mpm-ac-ks-small.c:46
#1  0x000055769613af7f in PMGetProtoInspect (rflow=0x7f155fe48527, pm_results=0x7f155fe48440, direction=41 ')', buflen=397, buf=0x0, f=0x7f15203aa6a0, mpm_tctx=<optimized out>,
    pm_ctx=0x557696647fe8 <alpd_ctx+72>, tctx=0x7f15242d12c0) at app-layer-detect-proto.c:275
#2  AppLayerProtoDetectPMGetProto (rflow=0x7f155fe48527, pm_results=0x7f155fe48440, direction=41 ')', buflen=397, buf=0x0, f=0x7f15203aa6a0, tctx=0x7f15242d12c0) at app-layer-detect-proto.c:342
#3  AppLayerProtoDetectGetProto (tctx=0x7f15242d12c0, f=f@entry=0x7f15203aa6a0, buf=buf@entry=0x0, buflen=buflen@entry=397, ipproto=ipproto@entry=6 '\006', direction=direction@entry=41 ')',
    reverse_flow=0x7f155fe48527) at app-layer-detect-proto.c:1551
#4  0x0000557696138df4 in TCPProtoDetect (tv=0x5576b75b1fa0, ra_ctx=0x7f15242d1270, app_tctx=app_tctx@entry=0x7f15242d12a0, p=p@entry=0x7f1524274150, f=f@entry=0x7f15203aa6a0,
    ssn=ssn@entry=0x7f151c3321b0, stream=0x7f155fe48648, data=0x0, data_len=397, flags=41 ')') at app-layer.c:336
#5  0x0000557696139921 in AppLayerHandleTCPData (tv=tv@entry=0x5576b75b1fa0, ra_ctx=ra_ctx@entry=0x7f15242d1270, p=p@entry=0x7f1524274150, f=0x7f15203aa6a0, ssn=ssn@entry=0x7f151c3321b0,
    stream=stream@entry=0x7f155fe48648, data=0x0, data_len=397, flags=41 ')') at app-layer.c:642
#6  0x000055769622dbb7 in ReassembleUpdateAppLayer (dir=UPDATE_DIR_PACKET, p=0x7f1524274150, stream=0x7f155fe48648, ssn=0x7f151c3321b0, ra_ctx=0x7f15242d1270, tv=0x5576b75b1fa0)
    at stream-tcp-reassemble.c:1175
#7  StreamTcpReassembleAppLayer (tv=tv@entry=0x5576b75b1fa0, ra_ctx=ra_ctx@entry=0x7f15242d1270, ssn=ssn@entry=0x7f151c3321b0, stream=<optimized out>, stream@entry=0x7f151c3321c0,
    p=p@entry=0x7f1524274150, dir=dir@entry=UPDATE_DIR_PACKET) at stream-tcp-reassemble.c:1238
#8  0x000055769622eb23 in StreamTcpReassembleHandleSegment (tv=tv@entry=0x5576b75b1fa0, ra_ctx=0x7f15242d1270, ssn=ssn@entry=0x7f151c3321b0, stream=0x7f151c3321c0, p=p@entry=0x7f1524274150,
    pq=pq@entry=0x7f15242d0f68) at stream-tcp-reassemble.c:1900
#9  0x000055769622392e in HandleEstablishedPacketToClient (stt=<optimized out>, pq=<optimized out>, p=<optimized out>, ssn=<optimized out>, tv=<optimized out>) at stream-tcp.c:2318
#10 StreamTcpPacketStateEstablished (tv=0x5576b75b1fa0, p=0x7f1524274150, stt=stt@entry=0x7f15242d0f60, ssn=0x7f151c3321b0, pq=0x7f15242d0f68) at stream-tcp.c:2702
#11 0x0000557696228da8 in StreamTcpStateDispatch (tv=0x5576b75b1fa0, p=0x7f1524274150, stt=0x7f15242d0f60, ssn=0x7f151c3321b0, pq=0x7f15242d0f68, state=<optimized out>) at stream-tcp.c:4703
#12 0x000055769622a682 in StreamTcpPacket (tv=0x5576b75b1fa0, p=0x7f1524274150, stt=0x7f15242d0f60, pq=0x7f15242aeb40) at stream-tcp.c:4889
#13 0x000055769622ae24 in StreamTcp (tv=tv@entry=0x5576b75b1fa0, p=p@entry=0x7f1524274150, data=<optimized out>, pq=pq@entry=0x7f15242aeb40) at stream-tcp.c:5225
#14 0x00005576961e2a2f in FlowWorkerStreamTCPUpdate (detect_thread=0x7f15243a3520, p=0x7f1524274150, fw=0x7f15242aeb10, tv=0x5576b75b1fa0) at flow-worker.c:524
#15 FlowWorker (tv=0x5576b75b1fa0, p=0x7f1524274150, data=0x7f15242aeb10) at flow-worker.c:524
#16 0x0000557696235fa2 in TmThreadsSlotVarRun (tv=tv@entry=0x5576b75b1fa0, p=p@entry=0x7f1524274150, slot=<optimized out>) at tm-threads.c:117
#17 0x0000557696219102 in TmThreadsSlotProcessPkt (p=0x7f1524274150, s=<optimized out>, tv=0x5576b75b1fa0) at tm-threads.h:192
#18 AFPReadFromRing (ptv=ptv@entry=0x7f1524274b20) at source-af-packet.c:1011
#19 0x00005576962196c9 in ReceiveAFPLoop (tv=0x5576b75b1fa0, data=0x7f1524274b20, slot=<optimized out>) at source-af-packet.c:1571
#20 0x000055769623768c in TmThreadsSlotPktAcqLoop (td=0x5576b75b1fa0) at tm-threads.c:312
#21 0x00007f1562a5bfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#22 0x00007f1561bdd4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Going to try the last ac mode, but I think, it's gonna be the same...

pevma commented 3 years ago

Please let us know.

ssvinarev commented 3 years ago

Hi!

Tried the last ac mode. Same error. There is the dump:

Thread 8 (Thread 0x7f9564b53700 (LWP 1616)):
#0  0x00007f9568c01720 in __GI___nanosleep (requested_time=requested_time@entry=0x7f9564b52a10, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f9568c2c874 in usleep (useconds=useconds@entry=100) at ../sysdeps/posix/usleep.c:32
#2  0x000055af8b07f1a6 in FlowRecycler (th_v=0x55af99d4aea0, thread_data=0x7f950c000b20) at flow-manager.c:1210
#3  0x000055af8b0d76a2 in TmThreadsManagement (td=0x55af99d4aea0) at tm-threads.c:541
#4  0x00007f9569ab2fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f9568c344cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 7 (Thread 0x7f9565354700 (LWP 1612)):
#0  0x00007f9568c01720 in __GI___nanosleep (requested_time=requested_time@entry=0x7f95653539b0, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f9568c2c874 in usleep (useconds=useconds@entry=100) at ../sysdeps/posix/usleep.c:32
#2  0x000055af8b07fb33 in FlowManager (th_v=0x55af9b3bf3d0, thread_data=0x7f9508000b20) at flow-manager.c:1014
#3  0x000055af8b0d76a2 in TmThreadsManagement (td=0x55af9b3bf3d0) at tm-threads.c:541
#4  0x00007f9569ab2fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f9568c344cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 6 (Thread 0x7f95660f2700 (LWP 1611)):
#0  0x00007f9568c29819 in __GI___poll (fds=fds@entry=0x7f95660f19d0, nfds=nfds@entry=1, timeout=timeout@entry=100) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x000055af8b0b986d in poll (__timeout=100, __nfds=1, __fds=0x7f95660f19d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  ReceiveAFPLoop (tv=0x55af9b3ac550, data=0x7f9510278b20, slot=<optimized out>) at source-af-packet.c:1544
#3  0x000055af8b0d794c in TmThreadsSlotPktAcqLoop (td=0x55af9b3ac550) at tm-threads.c:312
#4  0x00007f9569ab2fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f9568c344cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 5 (Thread 0x7f9563350700 (LWP 1619)):
#0  0x00007f9568c2c037 in __GI___select (nfds=7, readfds=readfds@entry=0x7f956334f850, writefds=writefds@entry=0x0, exceptfds=exceptfds@entry=0x0, timeout=timeout@entry=0x7f956334f840)
    at ../sysdeps/unix/sysv/linux/select.c:41
#1  0x000055af8b0dadd5 in UnixMain (this=0x55af8b4f6f00 <command>) at unix-manager.c:650
#2  UnixManager (th_v=0x55af9186c8a0, thread_data=<optimized out>) at unix-manager.c:1125
#3  0x000055af8b0d76a2 in TmThreadsManagement (td=0x55af9186c8a0) at tm-threads.c:541
#4  0x00007f9569ab2fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f9568c344cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 4 (Thread 0x7f9564352700 (LWP 1617)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f9564351ad0, expected=0, futex_word=0x55afc9753008) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  __pthread_cond_wait_common (abstime=0x7f9564351ad0, mutex=0x55af9837fd50, cond=0x55afc9752fe0) at pthread_cond_wait.c:539
#2  __pthread_cond_timedwait (cond=0x55afc9752fe0, mutex=0x55af9837fd50, abstime=abstime@entry=0x7f9564351ad0) at pthread_cond_wait.c:667
#3  0x000055af8b00799c in StatsWakeupThread (arg=0x55af91865b40) at counters.c:487
#4  0x00007f9569ab2fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f9568c344cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 3 (Thread 0x7f9563b51700 (LWP 1618)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f9563b50ad0, expected=0, futex_word=0x55afc96f4638) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  __pthread_cond_wait_common (abstime=0x7f9563b50ad0, mutex=0x55af98368110, cond=0x55afc96f4610) at pthread_cond_wait.c:539
#2  __pthread_cond_timedwait (cond=0x55afc96f4610, mutex=0x55af98368110, abstime=abstime@entry=0x7f9563b50ad0) at pthread_cond_wait.c:667
#3  0x000055af8b007fe3 in StatsMgmtThread (arg=<optimized out>) at counters.c:415
#4  0x00007f9569ab2fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f9568c344cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 2 (Thread 0x7f95687a9b00 (LWP 1066)):
#0  0x00007f9568c01720 in __GI___nanosleep (requested_time=requested_time@entry=0x7fffb01f32c0, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f9568c2c874 in usleep (useconds=useconds@entry=10000) at ../sysdeps/posix/usleep.c:32
#2  0x000055af8b0d3dd7 in SuricataMainLoop (suri=<optimized out>) at suricata.c:2644
#3  SuricataMain (argc=<optimized out>, argv=<optimized out>) at suricata.c:2805
#4  0x00007f9568b5f09b in __libc_start_main (main=0x55af8afd6930 <main>, argc=9, argv=0x7fffb01f3418, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffb01f3408)
    at ../csu/libc-start.c:308
#5  0x000055af8afd696a in _start ()

Thread 1 (Thread 0x7f9566e90700 (LWP 1610)):
#0  SCACSearch (mpm_ctx=<optimized out>, mpm_thread_ctx=<optimized out>, pmq=<optimized out>, buf=0x0, buflen=<optimized out>) at util-mpm-ac.c:1038
#1  0x000055af8afdaf5f in PMGetProtoInspect (rflow=0x7f9566e8f527, pm_results=0x7f9566e8f440, direction=41 ')', buflen=210, buf=0x0, f=0x7f95082b9d90, mpm_tctx=<optimized out>,
    pm_ctx=0x55af8b4e7fc8 <alpd_ctx+72>, tctx=0x7f95282d53b0) at app-layer-detect-proto.c:275
#2  AppLayerProtoDetectPMGetProto (rflow=0x7f9566e8f527, pm_results=0x7f9566e8f440, direction=41 ')', buflen=210, buf=0x0, f=0x7f95082b9d90, tctx=0x7f95282d53b0) at app-layer-detect-proto.c:342
#3  AppLayerProtoDetectGetProto (tctx=0x7f95282d53b0, f=f@entry=0x7f95082b9d90, buf=buf@entry=0x0, buflen=buflen@entry=210, ipproto=ipproto@entry=6 '\006', direction=direction@entry=41 ')',
    reverse_flow=0x7f9566e8f527) at app-layer-detect-proto.c:1551
#4  0x000055af8afd8dd4 in TCPProtoDetect (tv=0x55af99d5a860, ra_ctx=0x7f95282d5360, app_tctx=app_tctx@entry=0x7f95282d5390, p=p@entry=0x7f9528278140, f=f@entry=0x7f95082b9d90,
    ssn=ssn@entry=0x7f9510d11870, stream=0x7f9566e8f648, data=0x0, data_len=210, flags=41 ')') at app-layer.c:336
#5  0x000055af8afd9901 in AppLayerHandleTCPData (tv=tv@entry=0x55af99d5a860, ra_ctx=ra_ctx@entry=0x7f95282d5360, p=p@entry=0x7f9528278140, f=0x7f95082b9d90, ssn=ssn@entry=0x7f9510d11870,
    stream=stream@entry=0x7f9566e8f648, data=0x0, data_len=210, flags=41 ')') at app-layer.c:642
#6  0x000055af8b0cde67 in ReassembleUpdateAppLayer (dir=UPDATE_DIR_PACKET, p=0x7f9528278140, stream=0x7f9566e8f648, ssn=0x7f9510d11870, ra_ctx=0x7f95282d5360, tv=0x55af99d5a860)
    at stream-tcp-reassemble.c:1174
#7  StreamTcpReassembleAppLayer (tv=tv@entry=0x55af99d5a860, ra_ctx=ra_ctx@entry=0x7f95282d5360, ssn=ssn@entry=0x7f9510d11870, stream=<optimized out>, stream@entry=0x7f9510d11880,
    p=p@entry=0x7f9528278140, dir=dir@entry=UPDATE_DIR_PACKET) at stream-tcp-reassemble.c:1237
#8  0x000055af8b0cedd3 in StreamTcpReassembleHandleSegment (tv=tv@entry=0x55af99d5a860, ra_ctx=0x7f95282d5360, ssn=ssn@entry=0x7f9510d11870, stream=0x7f9510d11880, p=p@entry=0x7f9528278140,
    pq=pq@entry=0x7f95282d5058) at stream-tcp-reassemble.c:1899
#9  0x000055af8b0c3bee in HandleEstablishedPacketToClient (stt=<optimized out>, pq=<optimized out>, p=<optimized out>, ssn=<optimized out>, tv=<optimized out>) at stream-tcp.c:2318
#10 StreamTcpPacketStateEstablished (tv=0x55af99d5a860, p=0x7f9528278140, stt=stt@entry=0x7f95282d5050, ssn=0x7f9510d11870, pq=0x7f95282d5058) at stream-tcp.c:2702
#11 0x000055af8b0c9068 in StreamTcpStateDispatch (tv=0x55af99d5a860, p=0x7f9528278140, stt=0x7f95282d5050, ssn=0x7f9510d11870, pq=0x7f95282d5058, state=<optimized out>) at stream-tcp.c:4703
#12 0x000055af8b0ca942 in StreamTcpPacket (tv=0x55af99d5a860, p=0x7f9528278140, stt=0x7f95282d5050, pq=0x7f95282b2c20) at stream-tcp.c:4889
#13 0x000055af8b0cb0e4 in StreamTcp (tv=tv@entry=0x55af99d5a860, p=p@entry=0x7f9528278140, data=<optimized out>, pq=pq@entry=0x7f95282b2c20) at stream-tcp.c:5225
#14 0x000055af8b082ccf in FlowWorkerStreamTCPUpdate (detect_thread=0x7f95283a7610, p=0x7f9528278140, fw=0x7f95282b2bf0, tv=0x55af99d5a860) at flow-worker.c:524
#15 FlowWorker (tv=0x55af99d5a860, p=0x7f9528278140, data=0x7f95282b2bf0) at flow-worker.c:524
#16 0x000055af8b0d6262 in TmThreadsSlotVarRun (tv=tv@entry=0x55af99d5a860, p=p@entry=0x7f9528278140, slot=<optimized out>) at tm-threads.c:117
#17 0x000055af8b0b93c2 in TmThreadsSlotProcessPkt (p=0x7f9528278140, s=<optimized out>, tv=0x55af99d5a860) at tm-threads.h:192
#18 AFPReadFromRing (ptv=ptv@entry=0x7f9528278b20) at source-af-packet.c:1011
#19 0x000055af8b0b9989 in ReceiveAFPLoop (tv=0x55af99d5a860, data=0x7f9528278b20, slot=<optimized out>) at source-af-packet.c:1571
#20 0x000055af8b0d794c in TmThreadsSlotPktAcqLoop (td=0x55af99d5a860) at tm-threads.c:312
#21 0x00007f9569ab2fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#22 0x00007f9568c344cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
pevma commented 3 years ago

I've updated the ticket here too - https://redmine.openinfosecfoundation.org/issues/4273

ssvinarev commented 3 years ago

Hi

@pevma , you have been asked a few questions at https://redmine.openinfosecfoundation.org/issues/4273 Could you take a look?

PS: the problem is still relevant.

pevma commented 3 years ago

@ssvinarev - if you have a core , we can update the issue with the values needed. Do you have one we can use?

ssvinarev commented 3 years ago

There is the new dump. Current mpm-algo is ac-ks

# gdb /usr/bin/suricata /var/log/suricata/core/core
GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/suricata...Reading symbols from /usr/lib/debug/.build-id/fc/e362f0008a41cd200ce011256da92528dbe0b2.debug...done.
done.

warning: core file may not match specified executable file.
[New LWP 10546]
[New LWP 10548]
[New LWP 10464]
[New LWP 10550]
[New LWP 10551]
[New LWP 10552]
[New LWP 10547]
[New LWP 10549]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/bin/suricata -c /etc/suricata/suricata.yaml --pidfile /var/run/suricata.pi'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  SCACTileSearchTiny32 (ctx=0x55838a3427d0, mpm_thread_ctx=<optimized out>, pmq=0x7f1d5b1bd3b0, buf=0x0, buflen=8) at util-mpm-ac-ks-small.c:46
46      util-mpm-ac-ks-small.c: No such file or directory.
[Current thread is 1 (Thread 0x7f1da7a64700 (LWP 10546))]
(gdb)
(gdb) set logging on
Copying output to gdb.txt.
(gdb) thread apply all bt

Thread 8 (Thread 0x7f1da5727700 (LWP 10549)):
#0  0x00007f1da9830720 in __GI___nanosleep (requested_time=requested_time@entry=0x7f1da5726a10, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f1da985b874 in usleep (useconds=useconds@entry=100) at ../sysdeps/posix/usleep.c:32
#2  0x000055838981b1a6 in FlowRecycler (th_v=0x55839bdcf010, thread_data=0x7f1d3c000b20) at flow-manager.c:1210
#3  0x00005583898736a2 in TmThreadsManagement (td=0x55839bdcf010) at tm-threads.c:541
#4  0x00007f1daa6e1fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1da98634cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 7 (Thread 0x7f1da6cc6700 (LWP 10547)):
#0  0x00007f1da9858819 in __GI___poll (fds=fds@entry=0x7f1da6cc59d0, nfds=nfds@entry=1, timeout=timeout@entry=100) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x000055838985586d in poll (__timeout=100, __nfds=1, __fds=0x7f1da6cc59d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#2  ReceiveAFPLoop (tv=0x55839bccfb30, data=0x7f1d43160b20, slot=<optimized out>) at source-af-packet.c:1544
#3  0x000055838987394c in TmThreadsSlotPktAcqLoop (td=0x55839bccfb30) at tm-threads.c:312
#4  0x00007f1daa6e1fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1da98634cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 6 (Thread 0x7f1da3f24700 (LWP 10552)):
#0  0x00007f1da985b037 in __GI___select (nfds=7, readfds=readfds@entry=0x7f1da3f23850, writefds=writefds@entry=0x0, exceptfds=exceptfds@entry=0x0, timeout=timeout@entry=0x7f1da3f23840)
    at ../sysdeps/unix/sysv/linux/select.c:41
#1  0x0000558389876dd5 in UnixMain (this=0x558389c92f00 <command>) at unix-manager.c:650
#2  UnixManager (th_v=0x55838f05d900, thread_data=<optimized out>) at unix-manager.c:1125
#3  0x00005583898736a2 in TmThreadsManagement (td=0x55838f05d900) at tm-threads.c:541
#4  0x00007f1daa6e1fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1da98634cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 5 (Thread 0x7f1da4725700 (LWP 10551)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f1da4724ad0, expected=0, futex_word=0x5583cd6849b8) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  __pthread_cond_wait_common (abstime=0x7f1da4724ad0, mutex=0x5583cd716410, cond=0x5583cd684990) at pthread_cond_wait.c:539
#2  __pthread_cond_timedwait (cond=0x5583cd684990, mutex=0x5583cd716410, abstime=abstime@entry=0x7f1da4724ad0) at pthread_cond_wait.c:667
#3  0x00005583897a3fe3 in StatsMgmtThread (arg=<optimized out>) at counters.c:415
#4  0x00007f1daa6e1fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1da98634cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 4 (Thread 0x7f1da4f26700 (LWP 10550)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f1da4f25ad0, expected=0, futex_word=0x5583cca540f8) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1  __pthread_cond_wait_common (abstime=0x7f1da4f25ad0, mutex=0x5583953ee1e0, cond=0x5583cca540d0) at pthread_cond_wait.c:539
#2  __pthread_cond_timedwait (cond=0x5583cca540d0, mutex=0x5583953ee1e0, abstime=abstime@entry=0x7f1da4f25ad0) at pthread_cond_wait.c:667
#3  0x00005583897a399c in StatsWakeupThread (arg=0x55838f059050) at counters.c:487
#4  0x00007f1daa6e1fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1da98634cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 3 (Thread 0x7f1da93d8b00 (LWP 10464)):
#0  0x00007f1da9830720 in __GI___nanosleep (requested_time=requested_time@entry=0x7ffe4ea34370, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f1da985b874 in usleep (useconds=useconds@entry=10000) at ../sysdeps/posix/usleep.c:32
#2  0x000055838986fdd7 in SuricataMainLoop (suri=<optimized out>) at suricata.c:2644
#3  SuricataMain (argc=<optimized out>, argv=<optimized out>) at suricata.c:2805
#4  0x00007f1da978e09b in __libc_start_main (main=0x558389772930 <main>, argc=9, argv=0x7ffe4ea344c8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe4ea344b8)
    at ../csu/libc-start.c:308
#5  0x000055838977296a in _start ()

Thread 2 (Thread 0x7f1da5f28700 (LWP 10548)):
#0  0x00007f1da9830720 in __GI___nanosleep (requested_time=requested_time@entry=0x7f1da5f279b0, remaining=remaining@entry=0x0) at ../sysdeps/unix/sysv/linux/nanosleep.c:28
#1  0x00007f1da985b874 in usleep (useconds=useconds@entry=100) at ../sysdeps/posix/usleep.c:32
#2  0x000055838981bb33 in FlowManager (th_v=0x55839bdbc330, thread_data=0x7f1d38000b20) at flow-manager.c:1014
#3  0x00005583898736a2 in TmThreadsManagement (td=0x55839bdbc330) at tm-threads.c:541
#4  0x00007f1daa6e1fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#5  0x00007f1da98634cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
--Type <RET> for more, q to quit, c to continue without paging--

Thread 1 (Thread 0x7f1da7a64700 (LWP 10546)):
#0  SCACTileSearchTiny32 (ctx=0x55838a3427d0, mpm_thread_ctx=<optimized out>, pmq=0x7f1d5b1bd3b0, buf=0x0, buflen=8) at util-mpm-ac-ks-small.c:46
#1  0x0000558389776f5f in PMGetProtoInspect (rflow=0x7f1da7a63527, pm_results=0x7f1da7a63440, direction=41 ')', buflen=205, buf=0x0, f=0x7f1d3b771db0, mpm_tctx=<optimized out>,
    pm_ctx=0x558389c83fc8 <alpd_ctx+72>, tctx=0x7f1d5b1bd3b0) at app-layer-detect-proto.c:275
#2  AppLayerProtoDetectPMGetProto (rflow=0x7f1da7a63527, pm_results=0x7f1da7a63440, direction=41 ')', buflen=205, buf=0x0, f=0x7f1d3b771db0, tctx=0x7f1d5b1bd3b0) at app-layer-detect-proto.c:342
#3  AppLayerProtoDetectGetProto (tctx=0x7f1d5b1bd3b0, f=f@entry=0x7f1d3b771db0, buf=buf@entry=0x0, buflen=buflen@entry=205, ipproto=ipproto@entry=6 '\006', direction=direction@entry=41 ')',
    reverse_flow=0x7f1da7a63527) at app-layer-detect-proto.c:1551
#4  0x0000558389774dd4 in TCPProtoDetect (tv=0x5583abfd7e50, ra_ctx=0x7f1d5b1bd360, app_tctx=app_tctx@entry=0x7f1d5b1bd390, p=p@entry=0x7f1d5b160140, f=f@entry=0x7f1d3b771db0,
    ssn=ssn@entry=0x7f1d2539f4d0, stream=0x7f1da7a63648, data=0x0, data_len=205, flags=41 ')') at app-layer.c:336
#5  0x0000558389775901 in AppLayerHandleTCPData (tv=tv@entry=0x5583abfd7e50, ra_ctx=ra_ctx@entry=0x7f1d5b1bd360, p=p@entry=0x7f1d5b160140, f=0x7f1d3b771db0, ssn=ssn@entry=0x7f1d2539f4d0,
    stream=stream@entry=0x7f1da7a63648, data=0x0, data_len=205, flags=41 ')') at app-layer.c:642
#6  0x0000558389869e67 in ReassembleUpdateAppLayer (dir=UPDATE_DIR_PACKET, p=0x7f1d5b160140, stream=0x7f1da7a63648, ssn=0x7f1d2539f4d0, ra_ctx=0x7f1d5b1bd360, tv=0x5583abfd7e50)
    at stream-tcp-reassemble.c:1174
#7  StreamTcpReassembleAppLayer (tv=tv@entry=0x5583abfd7e50, ra_ctx=ra_ctx@entry=0x7f1d5b1bd360, ssn=ssn@entry=0x7f1d2539f4d0, stream=<optimized out>, stream@entry=0x7f1d2539f4e0,
    p=p@entry=0x7f1d5b160140, dir=dir@entry=UPDATE_DIR_PACKET) at stream-tcp-reassemble.c:1237
#8  0x000055838986add3 in StreamTcpReassembleHandleSegment (tv=tv@entry=0x5583abfd7e50, ra_ctx=0x7f1d5b1bd360, ssn=ssn@entry=0x7f1d2539f4d0, stream=0x7f1d2539f4e0, p=p@entry=0x7f1d5b160140,
    pq=pq@entry=0x7f1d5b1bd058) at stream-tcp-reassemble.c:1899
#9  0x000055838985fbee in HandleEstablishedPacketToClient (stt=<optimized out>, pq=<optimized out>, p=<optimized out>, ssn=<optimized out>, tv=<optimized out>) at stream-tcp.c:2318
#10 StreamTcpPacketStateEstablished (tv=0x5583abfd7e50, p=0x7f1d5b160140, stt=stt@entry=0x7f1d5b1bd050, ssn=0x7f1d2539f4d0, pq=0x7f1d5b1bd058) at stream-tcp.c:2702
#11 0x0000558389865068 in StreamTcpStateDispatch (tv=0x5583abfd7e50, p=0x7f1d5b160140, stt=0x7f1d5b1bd050, ssn=0x7f1d2539f4d0, pq=0x7f1d5b1bd058, state=<optimized out>) at stream-tcp.c:4703
#12 0x0000558389866942 in StreamTcpPacket (tv=0x5583abfd7e50, p=0x7f1d5b160140, stt=0x7f1d5b1bd050, pq=0x7f1d5b19ac20) at stream-tcp.c:4889
#13 0x00005583898670e4 in StreamTcp (tv=tv@entry=0x5583abfd7e50, p=p@entry=0x7f1d5b160140, data=<optimized out>, pq=pq@entry=0x7f1d5b19ac20) at stream-tcp.c:5225
#14 0x000055838981eccf in FlowWorkerStreamTCPUpdate (detect_thread=0x55841d6e8750, p=0x7f1d5b160140, fw=0x7f1d5b19abf0, tv=0x5583abfd7e50) at flow-worker.c:524
#15 FlowWorker (tv=0x5583abfd7e50, p=0x7f1d5b160140, data=0x7f1d5b19abf0) at flow-worker.c:524
#16 0x0000558389872262 in TmThreadsSlotVarRun (tv=tv@entry=0x5583abfd7e50, p=p@entry=0x7f1d5b160140, slot=<optimized out>) at tm-threads.c:117
#17 0x00005583898553c2 in TmThreadsSlotProcessPkt (p=0x7f1d5b160140, s=<optimized out>, tv=0x5583abfd7e50) at tm-threads.h:192
#18 AFPReadFromRing (ptv=ptv@entry=0x7f1d5b160b20) at source-af-packet.c:1011
#19 0x0000558389855989 in ReceiveAFPLoop (tv=0x5583abfd7e50, data=0x7f1d5b160b20, slot=<optimized out>) at source-af-packet.c:1571
#20 0x000055838987394c in TmThreadsSlotPktAcqLoop (td=0x5583abfd7e50) at tm-threads.c:312
#21 0x00007f1daa6e1fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#22 0x00007f1da98634cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(gdb)
pevma commented 3 years ago

@ssvinarev - can you try to print those out

f->alproto

f->alproto_ts

f->alproto_tc

f->flags
ssvinarev commented 3 years ago

Sure, but what exactly I need to do for that?

pevma commented 3 years ago

gdb /usr/bin/suricata /var/log/suricata/core/core (make sure the paths to the core is the real one) then inside - try to print all these values

ssvinarev commented 3 years ago

Will this data be enough?

(gdb) bt full
#0  SCACTileSearchTiny32 (ctx=0x55838a3427d0, mpm_thread_ctx=<optimized out>, pmq=0x7f1d5b1bd3b0, buf=0x0, buflen=8) at util-mpm-ac-ks-small.c:46
        i = 0
        matches = 0
        mpm_bitarray = "\000\000"
        xlate = 0x55838a3427d8 "\001\002\003\004"
        state_table = 0x55838a353a10 "\200\200\200\200\200\201\203\211\217\200\200\200\200\200\200\200\225\200\200\200\242\200\232\236\200"
        state = 0 '\000'
        c = <optimized out>
#1  0x0000558389776f5f in PMGetProtoInspect (rflow=0x7f1da7a63527, pm_results=0x7f1da7a63440, direction=41 ')', buflen=205, buf=0x0, f=0x7f1d3b771db0, mpm_tctx=<optimized out>,
    pm_ctx=0x558389c83fc8 <alpd_ctx+72>, tctx=0x7f1d5b1bd3b0) at app-layer-detect-proto.c:275
        pm_matches = 0
        searchlen = 8
        search_cnt = <optimized out>
        pm_results_bf = "\000\000\000"
        pm_matches = <optimized out>
        searchlen = <optimized out>
        search_cnt = <optimized out>
        pm_results_bf = <optimized out>
        cnt = <optimized out>
        s = <optimized out>
        proto = <optimized out>
#2  AppLayerProtoDetectPMGetProto (rflow=0x7f1da7a63527, pm_results=0x7f1da7a63440, direction=41 ')', buflen=205, buf=0x0, f=0x7f1d3b771db0, tctx=0x7f1d5b1bd3b0) at app-layer-detect-proto.c:342
        pm_ctx = 0x558389c83fc8 <alpd_ctx+72>
        mpm_tctx = <optimized out>
        m = -1
        pm_ctx = <optimized out>
        mpm_tctx = <optimized out>
        m = <optimized out>
        om = <optimized out>
#3  AppLayerProtoDetectGetProto (tctx=0x7f1d5b1bd3b0, f=f@entry=0x7f1d3b771db0, buf=buf@entry=0x0, buflen=buflen@entry=205, ipproto=ipproto@entry=6 '\006', direction=direction@entry=41 ')',
    reverse_flow=0x7f1da7a63527) at app-layer-detect-proto.c:1551
        pm_results = {0, 15223, 32541, 0, 29408, 56344, 21891, 0, 28928, 53986, 21891, 0, 0, 0, 0, 0, 0, 2, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 2, 0, 0}
        pm_matches = <optimized out>
        alproto = 0
        pm_alproto = 0
#4  0x0000558389774dd4 in TCPProtoDetect (tv=0x5583abfd7e50, ra_ctx=0x7f1d5b1bd360, app_tctx=app_tctx@entry=0x7f1d5b1bd390, p=p@entry=0x7f1d5b160140, f=f@entry=0x7f1d3b771db0,
    ssn=ssn@entry=0x7f1d2539f4d0, stream=0x7f1da7a63648, data=0x0, data_len=205, flags=41 ')') at app-layer.c:336
        alproto = 0x7f1d3b771e6e
        alproto_otherdir = 0x7f1d3b771e6c
        direction = 1
        reverse_flow = false
#5  0x0000558389775901 in AppLayerHandleTCPData (tv=tv@entry=0x5583abfd7e50, ra_ctx=ra_ctx@entry=0x7f1d5b1bd360, p=p@entry=0x7f1d5b160140, f=0x7f1d3b771db0, ssn=ssn@entry=0x7f1d2539f4d0,
    stream=stream@entry=0x7f1da7a63648, data=0x0, data_len=205, flags=41 ')') at app-layer.c:642
        app_tctx = <optimized out>
        alproto = <optimized out>
        r = 0
        direction = 1
#6  0x0000558389869e67 in ReassembleUpdateAppLayer (dir=UPDATE_DIR_PACKET, p=0x7f1d5b160140, stream=0x7f1da7a63648, ssn=0x7f1d2539f4d0, ra_ctx=0x7f1d5b1bd360, tv=0x5583abfd7e50)
    at stream-tcp-reassemble.c:1174
        flags = <optimized out>
        check_for_gap_ahead = <optimized out>
        new_app_progress = <optimized out>
        mydata = 0x0
        mydata_len = 205
        app_progress = 0
        gap_ahead = <optimized out>
        last_was_gap = false
        app_progress = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        mydata = <optimized out>
        mydata_len = <optimized out>
        gap_ahead = <optimized out>
        last_was_gap = <optimized out>
        flags = <optimized out>
        check_for_gap_ahead = <optimized out>
        new_app_progress = <optimized out>
        r = <optimized out>
        no_progress_update = <optimized out>
#7  StreamTcpReassembleAppLayer (tv=tv@entry=0x5583abfd7e50, ra_ctx=ra_ctx@entry=0x7f1d5b1bd360, ssn=ssn@entry=0x7f1d2539f4d0, stream=<optimized out>, stream@entry=0x7f1d2539f4e0,
    p=p@entry=0x7f1d5b160140, dir=dir@entry=UPDATE_DIR_PACKET) at stream-tcp-reassemble.c:1237
No locals.
#8  0x000055838986add3 in StreamTcpReassembleHandleSegment (tv=tv@entry=0x5583abfd7e50, ra_ctx=0x7f1d5b1bd360, ssn=ssn@entry=0x7f1d2539f4d0, stream=0x7f1d2539f4e0, p=p@entry=0x7f1d5b160140,
    pq=pq@entry=0x7f1d5b1bd058) at stream-tcp-reassemble.c:1899
        opposing_stream = 0x7f1d2539f560
        dir = UPDATE_DIR_PACKET
#9  0x000055838985fbee in HandleEstablishedPacketToClient (stt=<optimized out>, pq=<optimized out>, p=<optimized out>, ssn=<optimized out>, tv=<optimized out>) at stream-tcp.c:2318
        zerowindowprobe = <optimized out>
        zerowindowprobe = <optimized out>
        ack_diff = <optimized out>
        ack_diff = <optimized out>
        ack_diff = <optimized out>
        ack_diff = <optimized out>
        sacked_size__ = <optimized out>
#10 StreamTcpPacketStateEstablished (tv=0x5583abfd7e50, p=0x7f1d5b160140, stt=stt@entry=0x7f1d5b1bd050, ssn=0x7f1d2539f4d0, pq=0x7f1d5b1bd058) at stream-tcp.c:2702
No locals.
#11 0x0000558389865068 in StreamTcpStateDispatch (tv=0x5583abfd7e50, p=0x7f1d5b160140, stt=0x7f1d5b1bd050, ssn=0x7f1d2539f4d0, pq=0x7f1d5b1bd058, state=<optimized out>) at stream-tcp.c:4703
No locals.
#12 0x0000558389866942 in StreamTcpPacket (tv=0x5583abfd7e50, p=0x7f1d5b160140, stt=0x7f1d5b1bd050, pq=0x7f1d5b19ac20) at stream-tcp.c:4889
        ssn = 0x7f1d2539f4d0
#13 0x00005583898670e4 in StreamTcp (tv=tv@entry=0x5583abfd7e50, p=p@entry=0x7f1d5b160140, data=<optimized out>, pq=pq@entry=0x7f1d5b19ac20) at stream-tcp.c:5225
        stt = <optimized out>
#14 0x000055838981eccf in FlowWorkerStreamTCPUpdate (detect_thread=0x55841d6e8750, p=0x7f1d5b160140, fw=0x7f1d5b19abf0, tv=0x5583abfd7e50) at flow-worker.c:524
        x = <optimized out>
        x = <optimized out>
#15 FlowWorker (tv=0x5583abfd7e50, p=0x7f1d5b160140, data=0x7f1d5b19abf0) at flow-worker.c:524
        fw = 0x7f1d5b19abf0
        detect_thread = 0x55841d6e8750
#16 0x0000558389872262 in TmThreadsSlotVarRun (tv=tv@entry=0x5583abfd7e50, p=p@entry=0x7f1d5b160140, slot=<optimized out>) at tm-threads.c:117
        r = <optimized out>
        s = 0x55839552eae0
#17 0x00005583898553c2 in TmThreadsSlotProcessPkt (p=0x7f1d5b160140, s=<optimized out>, tv=0x5583abfd7e50) at tm-threads.h:192
        r = <optimized out>
        r = <optimized out>
#18 AFPReadFromRing (ptv=ptv@entry=0x7f1d5b160b20) at source-af-packet.c:1011
        p = 0x7f1d5b160140
        h = {h2 = 0x7f1d57fb71a0, h3 = 0x7f1d57fb71a0, raw = 0x7f1d57fb71a0}
        emergency_flush = 0 '\000'
        read_pkts = 2
        loop_start = -1
#19 0x0000558389855989 in ReceiveAFPLoop (tv=0x5583abfd7e50, data=0x7f1d5b160b20, slot=<optimized out>) at source-af-packet.c:1571
        ptv = 0x7f1d5b160b20
        fds = {fd = 7, events = 1, revents = 1}
        r = <optimized out>
        s = <optimized out>
        last_dump = 1626694085
        current_time = <optimized out>
        AFPReadFunc = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        discarded_pkts = <optimized out>
        __FUNCTION__ = "ReceiveAFPLoop"
#20 0x000055838987394c in TmThreadsSlotPktAcqLoop (td=0x5583abfd7e50) at tm-threads.c:312
        tv = 0x5583abfd7e50
        s = 0x5583b8b042b0
        run = 1 '\001'
        r = <optimized out>
        slot = <optimized out>
        __FUNCTION__ = "TmThreadsSlotPktAcqLoop"
#21 0x00007f1daa6e1fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
        ret = <optimized out>
        pd = <optimized out>
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139765343471360, -8490725896049826362, 140730217742686, 140730217742687, 139765343471360, 140730217742960, 8363657869228074438,
                8363665083564254662}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
#22 0x00007f1da98634cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
No locals.
pevma commented 3 years ago

Thank you @ssvinarev I just updated the issue (https://redmine.openinfosecfoundation.org/issues/4273). Please feel free to update it directly if more info is needed as well.

pevma commented 3 years ago

@ssvinarev - can you try this PR https://github.com/catenacyber/suricata/tree/protodetect-midstream-gap-4273-v2 ? I can guide you to what you need to do to compile it and have it running locally as a test.

ssvinarev commented 3 years ago

Hi, @pevma !

Locally it will be difficult to reproduce load pattern, that causes service failures. But I think, I will be able to test this on a real traffic.

Please, guide me, what to do. Am I right, that in fact I need to recompile /usr/bin/suricata binary and replace current binary with changed one?

pevma commented 3 years ago

You can basically follow this guide here:
https://github.com/StamusNetworks/SELKS/wiki/How-to-compile-latest-Suricata-on-SELKS However instead of doing

git clone https://github.com/OISF/suricata.git && cd suricata \
&& git clone https://github.com/OISF/libhtp.git -b 0.5.x

do

git clone -b protodetect-midstream-gap-4273-v2 https://github.com/catenacyber/suricata.git  && cd suricata \
&& git clone https://github.com/OISF/libhtp.git -b 0.5.x
.....

Test out first in your QA environment please :)

pevma commented 3 years ago

@ssvinarev - any feedback if it is better or not ?

ssvinarev commented 3 years ago

Haven't tested yet, didn't have time.