Project

General

Profile

Actions

Bug #2039

closed

suricata stops processing when http-log output via unix_stream backs up

Added by Jason Taylor almost 8 years ago. Updated over 7 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Target version:
Affected Versions:
Effort:
Difficulty:
Label:

Description

Issue: If the http-log is enabled and set to output to a unix_stream and if the application reading from the unix_stream stops reading, suricata appears to stop processing data.

To reproduce:

- http-log:
enabled: yes
filename: /path/to/suricata-http.sock
append: yes
#extended: yes # enable this for extended logging information
custom: yes # enabled the custom logging format (defined by customformat)
customformat: "%{%D-%H:%M:%S}t.%z|warmiusedc_eext_01|%a|%p|%A|%P|%{X-Forwarded-For}i|%m|%h|%u|%{referer}i|%{User-agent}i|%{Accept-Language}i|%s"
filetype: unix_stream # 'regular', 'unix_stream' or 'unix_dgram'

depending on how much traffic is being fed to suricata this may take a few minutes or longer and suricata will stop writing alerts to eve.log.

Versions: 3.1.2 and 3.2.1

OS: CentOS Linux release 7.2.1511 (Core)

Suricata build-info:

This is Suricata version 3.1.2 RELEASE
Features: NFQ PCAP_SET_BUFF LIBPCAP_VERSION_MAJOR=1 AF_PACKET HAVE_PACKET_FANOUT LIBCAP_NG LIBNET1.1 HAVE_HTP_URI_NORMALIZE_HOOK PCRE_JIT HAVE_NSS HAVE_LUA HAVE_LIBJANSSON TLS
SIMD support: none
Atomic intrisics: 1 2 4 8 byte(s)
64-bits, Little-endian architecture
GCC version 4.8.5 20150623 (Red Hat 4.8.5-4), C version 199901
compiled with _FORTIFY_SOURCE=2
L1 cache line size (CLS)=64
thread local storage method: __thread
compiled with LibHTP v0.5.22, linked against LibHTP v0.5.22

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

Unix socket enabled:                     yes
Detection enabled: yes
libnss support:                          yes
libnspr support: yes
libjansson support: yes
hiredis support: no
Prelude support: no
PCRE jit: yes
LUA support: yes
libluajit: no
libgeoip: yes
Non-bundled htp: no
Old barnyard2 support: no
CUDA enabled: no
Hyperscan support: no
Libnet support: yes
Suricatasc install:                      yes
Profiling enabled:                       no
Profiling locks enabled: no

Development settings:
Coccinelle / spatch: no
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
Host:                                    x86_64-redhat-linux-gnu
Compiler: gcc -std=gnu99 (exec name) / gcc (real)
GCC Protect enabled: yes
GCC march native enabled: no
GCC Profile enabled: no
Position Independent Executable enabled: yes
CFLAGS -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector-strong --param=ssp-buffer-size=4 -grecord-gcc-switches -m64 -mtune=generic
PCAP_CFLAGS
SECCFLAGS -fstack-protector -D_FORTIFY_SOURCE=2 -Wformat -Wformat-security

This is Suricata version 3.2.1 RELEASE
Features: NFQ PCAP_SET_BUFF LIBPCAP_VERSION_MAJOR=1 AF_PACKET HAVE_PACKET_FANOUT LIBCAP_NG LIBNET1.1 HAVE_HTP_URI_NORMALIZE_HOOK PCRE_JIT HAVE_NSS HAVE_LUA HAVE_LIBJANSSON TLS MAGIC
SIMD support: none
Atomic intrisics: 1 2 4 8 byte(s)
64-bits, Little-endian architecture
GCC version 4.8.5 20150623 (Red Hat 4.8.5-11), C version 199901
compiled with _FORTIFY_SOURCE=2
L1 cache line size (CLS)=64
thread local storage method: __thread
compiled with LibHTP v0.5.23, linked against LibHTP v0.5.23

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

Unix socket enabled:                     yes
Detection enabled: yes
Libmagic support:                        yes
libnss support: yes
libnspr support: yes
libjansson support: yes
hiredis support: no
Prelude support: no
PCRE jit: yes
LUA support: yes
libluajit: no
libgeoip: yes
Non-bundled htp: no
Old barnyard2 support: no
CUDA enabled: no
Hyperscan support: no
Libnet support: yes
Suricatasc install:                      yes
Profiling enabled:                       no
Profiling locks enabled: no

Development settings:
Coccinelle / spatch: no
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
Host:                                    x86_64-redhat-linux-gnu
Compiler: gcc -std=gnu99 (exec name) / gcc (real)
GCC Protect enabled: yes
GCC march native enabled: no
GCC Profile enabled: no
Position Independent Executable enabled: yes
CFLAGS -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector-strong --param=ssp-buffer-size=4 -grecord-gcc-switches -m64 -mtune=generic
PCAP_CFLAGS
SECCFLAGS -fstack-protector -D_FORTIFY_SOURCE=2 -Wformat -Wformat-security
Actions #1

Updated by Jason Ish almost 8 years ago

I think this applies to any output using unix_stream and not just http.

As the stream connection is blocking, it will block when the consumer stops reading (or can't keep up).

Suricata should probably use a non-blocking socket. If it can't write to the socket (ie: EWOULDBLOCK), the data should be buffered until a point in time that it can be written. Then there is also the question of how much data should be buffered before Suricata starts dropping events to keep memory usage under control.

Actions #2

Updated by Jason Ish almost 8 years ago

Kind of related:
https://redmine.openinfosecfoundation.org/issues/352

But Redis, or even Logstash probably serve the job of a message queue, we should still have a non-blocking way to get the logs there. Note that as this will most likely require buffering of events before sending over the socket, it is very likely events will get lost on Suricata shutdown. Given that I'd still recommend logging to a file, or perhaps to Redis, which is likely to consume the events much faster.

Actions #3

Updated by Jason Ish almost 8 years ago

I tried one way at solving the issue, and that is to just drop events from being logged if the write to the socket would block. The idea here is to prioritize packets over events. The PR is https://github.com/inliniac/suricata/pull/2603.

While its not ideal to drop events, I think its better than blocking Suricata altogether.

Actions #4

Updated by Jason Taylor almost 8 years ago

Jason Ish wrote:

I tried one way at solving the issue, and that is to just drop events from being logged if the write to the socket would block. The idea here is to prioritize packets over events. The PR is https://github.com/inliniac/suricata/pull/2603.

While its not ideal to drop events, I think its better than blocking Suricata altogether.

Thanks Jason for looking at this! For our specific issue, this approach is what we were hoping for.

Actions #5

Updated by Jason Ish over 7 years ago

  • Status changed from New to Assigned
  • Assignee set to Jason Ish
  • Target version set to 70
Actions #6

Updated by Jason Ish over 7 years ago

  • Status changed from Assigned to Closed
  • Target version changed from 70 to 4.0beta1

Fixed, see https://github.com/inliniac/suricata/pull/2651#issuecomment-292464512

This changes the way the socket is written to detect if the write would block. If so the event is thrown away. You can see this number at exit. Getting it into a real time stat is another task I'll be looking into.

Actions

Also available in: Atom PDF