[Oisf-users] Bug: suricata won't terminate in runmode: auto

[elof2 at sentor.se]

On Sat, 28 Nov 2015, Peter Manev wrote:

> On Fri, Nov 27, 2015 at 9:23 PM,  <elof2 at sentor.se> wrote:
>>
>> Hi!
>> I'm new to suricata and have just signed up to this mail list.
>>
>>
>> Hi folks! :-)
>>
>>
>>
>> My first mail will be a bug report:
>> (should reports like this be reported here or put directly in the bug
>> tracker?)
>>
>>
>> I've found a reproduceable problem running suricata 2.0.9 in runmode: auto
>> on FreeBSD.
>>
>> The problem is that the suricata process won't terminate correctly.
>>
>> In 'autofp', 'workers' and 'single' mode, a ctrl-c will terminate suricata
>> correctly, while in 'auto' mode I get:
>>
>> # /usr/local/bin/suricata -i ix1 --pidfile /var/run/suricata.pid -c
>> /usr/local/etc/suricata/suricata.yaml -vv
>> 27/11/2015 -- 15:17:55 - <Notice> - This is Suricata version 2.0.9 RELEASE
>> 27/11/2015 -- 15:17:55 - <Info> - CPUs/cores online: 8
>> 27/11/2015 -- 15:17:55 - <Info> - 'default' server has
>> 'request-body-minimal-inspect-size' set to 33882 and
>> 'request-body-inspect-window' set to 4053 after randomization.
>> 27/11/2015 -- 15:17:55 - <Info> - 'default' server has
>> 'response-body-minimal-inspect-size' set to 33695 and
>> 'response-body-inspect-window' set to 4218 after randomization.
>> 27/11/2015 -- 15:17:55 - <Info> - HTTP memcap: 268435456
>> 27/11/2015 -- 15:17:55 - <Info> - DNS request flood protection level: 500
>> 27/11/2015 -- 15:17:55 - <Info> - DNS per flow memcap (state-memcap): 524288
>> 27/11/2015 -- 15:17:55 - <Info> - DNS global memcap: 33554432
>> 27/11/2015 -- 15:17:55 - <Info> - allocated 1572864 bytes of memory for the
>> defrag hash... 65536 buckets of size 24
>> 27/11/2015 -- 15:17:55 - <Info> - preallocated 65535 defrag trackers of size
>> 136
>> 27/11/2015 -- 15:17:55 - <Info> - defrag memory usage: 10485624 bytes,
>> maximum: 536870912
>> 27/11/2015 -- 15:17:55 - <Info> - AutoFP mode using default "Active Packets"
>> flow load balancer
>> 27/11/2015 -- 15:17:55 - <Info> - preallocated 10000 packets. Total memory
>> 34220000
>> 27/11/2015 -- 15:17:55 - <Info> - allocated 262144 bytes of memory for the
>> host hash... 4096 buckets of size 64
>> 27/11/2015 -- 15:17:55 - <Info> - preallocated 1000 hosts of size 80
>> 27/11/2015 -- 15:17:55 - <Info> - host memory usage: 358144 bytes, maximum:
>> 16777216
>> 27/11/2015 -- 15:17:55 - <Info> - allocated 67108864 bytes of memory for the
>> flow hash... 1048576 buckets of size 64
>> 27/11/2015 -- 15:17:56 - <Info> - preallocated 1048576 flows of size 216
>> 27/11/2015 -- 15:17:56 - <Info> - flow memory usage: 301989888 bytes,
>> maximum: 671088640
>> 27/11/2015 -- 15:17:56 - <Info> - stream "prealloc-sessions": 20000 (per
>> thread)
>> 27/11/2015 -- 15:17:56 - <Info> - stream "memcap": 1073741824
>> 27/11/2015 -- 15:17:56 - <Info> - stream "midstream" session pickups:
>> disabled
>> 27/11/2015 -- 15:17:56 - <Info> - stream "async-oneside": disabled
>> 27/11/2015 -- 15:17:56 - <Info> - stream "checksum-validation": disabled
>> 27/11/2015 -- 15:17:56 - <Info> - stream."inline": disabled
>> 27/11/2015 -- 15:17:56 - <Info> - stream "max-synack-queued": 5
>> 27/11/2015 -- 15:17:56 - <Info> - stream.reassembly "memcap": 2147483648
>> 27/11/2015 -- 15:17:56 - <Info> - stream.reassembly "depth": 1048576
>> 27/11/2015 -- 15:17:56 - <Info> - stream.reassembly "toserver-chunk-size":
>> 2463
>> 27/11/2015 -- 15:17:56 - <Info> - stream.reassembly "toclient-chunk-size":
>> 2452
>> 27/11/2015 -- 15:17:56 - <Info> - stream.reassembly.raw: enabled
>> 27/11/2015 -- 15:17:56 - <Info> - segment pool: pktsize 4, prealloc 256
>> 27/11/2015 -- 15:17:56 - <Info> - segment pool: pktsize 16, prealloc 512
>> 27/11/2015 -- 15:17:56 - <Info> - segment pool: pktsize 112, prealloc 512
>> 27/11/2015 -- 15:17:56 - <Info> - segment pool: pktsize 248, prealloc 512
>> 27/11/2015 -- 15:17:56 - <Info> - segment pool: pktsize 512, prealloc 512
>> 27/11/2015 -- 15:17:56 - <Info> - segment pool: pktsize 768, prealloc 1024
>> 27/11/2015 -- 15:17:56 - <Info> - segment pool: pktsize 1448, prealloc 1024
>> 27/11/2015 -- 15:17:56 - <Info> - segment pool: pktsize 65535, prealloc 128
>> 27/11/2015 -- 15:17:56 - <Info> - stream.reassembly "chunk-prealloc": 250
>> 27/11/2015 -- 15:17:56 - <Info> - IP reputation disabled
>> 27/11/2015 -- 15:17:56 - <Info> - using magic-file /usr/share/misc/magic
>> 27/11/2015 -- 15:17:56 - <Info> - Delayed detect disabled
>> 27/11/2015 -- 15:17:57 - <Info> - 7 rule files processed. 4970 rules
>> successfully loaded, 0 rules failed
>> 27/11/2015 -- 15:17:57 - <Info> - 4970 signatures processed. 0 are IP-only
>> rules, 1860 are inspecting packet payload, 3198 inspect application layer,
>> 91 are decoder event only
>> 27/11/2015 -- 15:17:57 - <Info> - building signature grouping structure,
>> stage 1: preprocessing rules... complete
>> 27/11/2015 -- 15:17:57 - <Info> - building signature grouping structure,
>> stage 2: building source address list... complete
>> 27/11/2015 -- 15:17:57 - <Info> - building signature grouping structure,
>> stage 3: building destination address lists... complete
>> 27/11/2015 -- 15:17:58 - <Info> - Threshold config parsed: 0 rule(s) found
>> 27/11/2015 -- 15:17:58 - <Info> - Core dump size is unlimited.
>> 27/11/2015 -- 15:17:58 - <Info> - fast output device (regular) initialized:
>> fast.log
>> 27/11/2015 -- 15:17:58 - <Info> - Using 1 live device(s).
>> 27/11/2015 -- 15:17:58 - <Info> - using interface ix1
>> 27/11/2015 -- 15:17:58 - <Info> - Set snaplen to 1518 for 'ix1'
>> 27/11/2015 -- 15:17:58 - <Info> - Going to use pcap buffer size of 64000000
>> 27/11/2015 -- 15:17:58 - <Info> - RunModeIdsPcapAuto initialised
>> 27/11/2015 -- 15:17:58 - <Notice> - all 16 packet processing threads, 3
>> management threads initialized, engine started.
>>
>> So far everything is good. Suricata is inspecting the incoming traffic.
>> When I now press ctrl-c, it starts to terminate like this:
>>
>> ^C27/11/2015 -- 16:47:34 - <Notice> - Signal Received.  Stopping engine.
>> 27/11/2015 -- 16:47:34 - <Info> - 0 new flows, 0 established flows were
>> timed out, 0 flows in closed state
>> ^C^C^C^C^C
>> ^C^C^C^C
>>
>> ...but it won't die.
>> I press ctrl-c some more. Nope.
>> I wait a few minutes. Nope.
>
> Is there traffic passing through the sniffing interface in that case scenario ?

Yes, I've pressed ctrl-c both when there's traffic flowing on ix1 as well 
as when it is completely silent. Same result.
(I also get the same result if I start suricata and then press ctrl-c 
after a few seconds without it having seen a single packet).



>> In another terminal I run 'ps faxuww'
>> USER    PID  %CPU %MEM     VSZ    RSS TT  STAT STARTED       TIME COMMAND
>> root   1746   0.8  5.4 1075164 898064  0  S+    4:53PM    1:23.44
>> /usr/local/bin/suricata -i ix1 --pidfile /var/run/suricata.pid -c
>> /usr/local/etc/suricata/suricata.yaml -vv
>> I run 'kill 1746'. Nope.
>> I run 'kill -9 1746'. Finally it dies.
>>
>>
>> I've changed absolutely nothing except the runmode between the tests.
>> In auto mode, ctrl-c always hang the process like this. Reprodueable every
>> time.
>>
>> I'm testing this on a FreeBSD 10.1 amd64 with suricata 2.0.9 compiled from
>> freebsd-ports.
>>
>> Let me know what I can do to help debug this further.
>>
>> /Elof
>
> -- 
> Regards,
> Peter Manev
>