Project

General

Profile

Actions

Support #3104

closed

eve-nsm log of flow has timestamp much later than flow end

Added by Bill Homan over 4 years ago. Updated over 3 years ago.

Status:
Closed
Priority:
Normal
Affected Versions:
Label:

Description

I'm experimenting with suricata and examining flow logging in eve-nsm.json, and occasionally a flow is logged with a timestamp that is much later (hours or days later) than the flow end.
I've looked for issues in my system logs and suricata logs and found no indications of resource issues or suricata errors.
I've looked through bugs and not found any specifically tied to this kind of problem, though I have noticed some bugs related to deadlocks in the past.

Am I misunderstanding the data, or is this an indication that suricata (or one of its threads) is hanging for a long time before logging a finished flow?
Also, lmk if there is a better forum to ask this.

Here's an example json record (ip addresses removed):

{
"timestamp": "2019-08-01T14:49:27.001024+0000",
"flow_id": 110494497537784,
"event_type": "flow",
"src_ip": "x.x.x.x",
"src_port": 54150,
"dest_ip": "y.y.y.y",
"dest_port": 443,
"proto": "TCP",
"app_proto": "tls",
"flow": {
"pkts_toserver": 28,
"pkts_toclient": 11,
"bytes_toserver": 4392,
"bytes_toclient": 6954,
"start": "2019-07-31T20:59:50.818936+0000",
"end": "2019-07-31T21:01:47.119398+0000",
"age": 117,
"state": "established",
"reason": "timeout",
"alerted": false
},
"tcp": {
"tcp_flags": "1b",
"tcp_flags_ts": "1b",
"tcp_flags_tc": "1a",
"syn": true,
"fin": true,
"psh": true,
"ack": true,
"state": "close_wait"
}
}

TIA


Files

suricata-slpv1-20190804.yaml (66.2 KB) suricata-slpv1-20190804.yaml copnfig from system where example log event occurred Bill Homan, 08/04/2019 06:46 PM
Actions #1

Updated by Peter Manev over 4 years ago

It says age -

"age": 117

Is this a flow record that is logged hours and days after it actually closed ?
Usually the the timeouts control this behavior - https://github.com/OISF/suricata/blob/master/suricata.yaml.in#L1250

What is your set up like where you see this - live traffic/pcap/suricata version/ suricata --build-info output etc ?

Actions #2

Updated by Bill Homan over 4 years ago

Thanks for the response! Yes - the flow record is logged hours after flow end. I have other examples where the log timestamp is days later than flow end. This is live traffic, not replays, in an environment where the flow might have ended because of a routing change. The suricata instance is running on a moderately powerful AWS instance and was not under stress at the time of the above event.

The timeouts are configured exactly as in the link you provided.

Here's build-info output:

suricata --build-info
This is Suricata version 4.1.3 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 MAGIC RUST 
SIMD support: none
Atomic intrisics: 1 2 4 8 byte(s)
64-bits, Little-endian architecture
GCC version 5.4.0 20160609, C version 199901
compiled with _FORTIFY_SOURCE=2
L1 cache line size (CLS)=64
thread local storage method: __thread
compiled with LibHTP v0.5.30, linked against LibHTP v0.5.27

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
  liblzma support:                         yes
  hiredis support:                         yes
  hiredis async with libevent:             yes
  Prelude support:                         no
  PCRE jit:                                yes
  LUA support:                             yes, through luajit
  libluajit:                               yes
  libgeoip:                                yes
  Non-bundled htp:                         yes
  Old barnyard2 support:                   no
  Hyperscan support:                       no
  Libnet support:                          yes
  liblz4 support:                          yes

  Rust support:                            yes
  Rust strict mode:                        no
  Rust debug mode:                         no
  Rust compiler:                           rustc 1.30.0
  Rust cargo:                              cargo 1.30.0

  Install suricatasc:                      yes
  Install suricata-update:                 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
  --datarootdir                            /usr/share

  Host:                                    x86_64-pc-linux-gnu
  Compiler:                                gcc (exec name) / gcc (real)
  GCC Protect enabled:                     yes
  GCC march native enabled:                no
  GCC Profile enabled:                     no
  Position Independent Executable enabled: yes
  CFLAGS                                   -g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security -I${srcdir}/../rust/gen/c-headers
  PCAP_CFLAGS                               -I/usr/include
  SECCFLAGS                                -fstack-protector -D_FORTIFY_SOURCE=2 -Wformat -Wformat-security

Actions #3

Updated by Bill Homan over 4 years ago

I'm posting a copy of our config.

Actions #4

Updated by Peter Manev over 4 years ago

Can you please try the latest stable - 4.1.4 (you are currently on 4.1.3)
Also what i noticed is some mismatch which could result in unexpected behaviour -

compiled with LibHTP v0.5.30, linked against LibHTP v0.5.27

both should be
v0.5.30

It means the libhtp on the system has not been updated during the install or there is something else.

Actions #5

Updated by Bill Homan over 4 years ago

Thanks for the suggestion. Will update when I can apply.

Actions #6

Updated by Andreas Herz over 4 years ago

  • Status changed from New to Feedback
  • Assignee set to Community Ticket
  • Target version set to Support
Actions #7

Updated by Andreas Herz over 3 years ago

  • Status changed from Feedback to Closed

Hi, we're closing this issue since there have been no further responses.
If you think this bug is still relevant, try to test it again with the
most recent version of suricata and reopen the issue. If you want to
improve the bug report please take a look at
https://redmine.openinfosecfoundation.org/projects/suricata/wiki/Reporting_Bugs

Actions

Also available in: Atom PDF