[Snort-devel] Bugreport - 60 second timeout before shutdown

elof at ...969... elof at ...969...
Thu May 6 08:36:38 EDT 2010


No, this has nothing to do with syslogd. The snort process simply don't 
die as quickly as it used to.

I've tracked the problem down to this:
The more signatures you have, the longer it takes for snort to shutdown.


...so my first assumption that there were a 60 second timeout is false.
However, in prior snort versions, the process always died immediately 
after I killed it. Now the process take seconds or even a minute to shut 
down.

When restarting the snort service, it is a huge difference between having 
to wait 0.5 seconds or 60 seconds. So although this is not a bug, it is 
still a big inconvenience that I hope can be removed so that snort service 
restarts will be swift again.


Example:
I start snort v2.8.4.1 (Build 38) and then kill it. The process 
immediately disappear.
I start snort v2.8.5.2 (Build 121) on the same machine, using virtually 
the same configuration as the snort above. After I kill this process, it 
takes 63 seconds before it is gone.

The same test, using the same configuration, on a much faster machine 
give:
2.8.4.1 - immediately disappear
2.8.5.2 - disappear after 14 seconds



Not only does it take a long time for the process to terminate, it 
apparently also use a lot of CPU when dying.

Example of a snort process running:
USER    PID %CPU %MEM  STAT STARTED      TIME COMMAND
snort 13194  0.0 58.6  Ss   Tue12PM   0:34.46 snort -q -D -c snort.conf
snort 13194  0.0 58.6  Ss   Tue12PM   0:34.46 snort -q -D -c snort.conf
snort 13194  0.0 58.6  Ss   Tue12PM   0:34.46 snort -q -D -c snort.conf
snort 13194  0.0 58.6  Ss   Tue12PM   0:34.46 snort -q -D -c snort.conf
snort 13194  0.0 58.6  Ss   Tue12PM   0:34.48 snort -q -D -c snort.conf

The sniffer NIC have very little traffic, so the snort process is sleeping 
and its CPU usage is 0.0.

Now I kill pid 13194. (See how the CPU rises)

snort 13194  0.0 58.8  DLs  Tue12PM   0:34.49 snort -q -D -c snort.conf
snort 13194  0.1 59.8  DLs  Tue12PM   0:34.50 snort -q -D -c snort.conf
snort 13194  0.2 62.2  Rs   Tue12PM   0:35.05 snort -q -D -c snort.conf
snort 13194  3.0 64.8  DLs  Tue12PM   0:35.53 snort -q -D -c snort.conf
snort 13194  7.0 67.1  DLs  Tue12PM   0:36.06 snort -q -D -c snort.conf
snort 13194  8.9 67.7  Rs   Tue12PM   0:36.63 snort -q -D -c snort.conf
snort 13194 11.4 69.1  Rs   Tue12PM   0:37.26 snort -q -D -c snort.conf
snort 13194 13.1 69.0  DLs  Tue12PM   0:37.60 snort -q -D -c snort.conf
snort 13194 13.2 69.0  RLs  Tue12PM   0:37.79 snort -q -D -c snort.conf
snort 13194 13.4 70.1  DLs  Tue12PM   0:38.00 snort -q -D -c snort.conf
snort 13194 13.3 70.0  Rs   Tue12PM   0:38.53 snort -q -D -c snort.conf
snort 13194 16.8 70.5  Rs   Tue12PM   0:39.62 snort -q -D -c snort.conf
snort 13194 20.8 70.5  Rs   Tue12PM   0:40.67 snort -q -D -c snort.conf
snort 13194 24.5 70.8  Rs   Tue12PM   0:41.69 snort -q -D -c snort.conf
snort 13194 28.1 70.9  Rs   Tue12PM   0:42.74 snort -q -D -c snort.conf
snort 13194 31.4 71.2  Rs   Tue12PM   0:43.79 snort -q -D -c snort.conf
snort 13194 34.6 72.0  DLs  Tue12PM   0:44.08 snort -q -D -c snort.conf
snort 13194 32.4 72.2  DLs  Tue12PM   0:44.10 snort -q -D -c snort.conf
snort 13194 31.7 72.1  DLs  Tue12PM   0:44.30 snort -q -D -c snort.conf
snort 13194 30.8 72.8  DLs  Tue12PM   0:44.44 snort -q -D -c snort.conf
snort 13194 29.8 73.1  DLs  Tue12PM   0:44.55 snort -q -D -c snort.conf
snort 13194 28.8 73.1  DLs  Tue12PM   0:44.67 snort -q -D -c snort.conf
snort 13194 27.7 73.2  DLs  Tue12PM   0:44.74 snort -q -D -c snort.conf
snort 13194 26.8 73.5  DLs  Tue12PM   0:44.86 snort -q -D -c snort.conf
snort 13194 25.9 74.2  DLs  Tue12PM   0:45.02 snort -q -D -c snort.conf
snort 13194 24.6 74.7  DLs  Tue12PM   0:45.16 snort -q -D -c snort.conf
snort 13194 24.0 75.0  DLs  Tue12PM   0:45.28 snort -q -D -c snort.conf
snort 13194 23.0 74.8  DLs  Tue12PM   0:45.38 snort -q -D -c snort.conf
snort 13194 22.5 75.2  DLs  Tue12PM   0:45.49 snort -q -D -c snort.conf
snort 13194 21.6 75.0  DLs  Tue12PM   0:45.62 snort -q -D -c snort.conf
snort 13194 21.0 75.3  Rs   Tue12PM   0:45.78 snort -q -D -c snort.conf
snort 13194 20.6 75.2  DLs  Tue12PM   0:46.00 snort -q -D -c snort.conf
snort 13194 20.5 75.5  DLs  Tue12PM   0:46.21 snort -q -D -c snort.conf
snort 13194 20.2 75.5  DLs  Tue12PM   0:46.36 snort -q -D -c snort.conf
snort 13194 19.8 75.8  DLs  Tue12PM   0:46.51 snort -q -D -c snort.conf
snort 13194 19.4 75.6  DLs  Tue12PM   0:46.67 snort -q -D -c snort.conf
snort 13194 19.3 75.5  DLs  Tue12PM   0:46.82 snort -q -D -c snort.conf
snort 13194 19.0 75.7  DLs  Tue12PM   0:46.97 snort -q -D -c snort.conf
snort 13194 18.8 75.6  DLs  Tue12PM   0:47.07 snort -q -D -c snort.conf
snort 13194 18.3 75.7  DLs  Tue12PM   0:47.14 snort -q -D -c snort.conf
snort 13194 18.3 75.8  DLs  Tue12PM   0:47.21 snort -q -D -c snort.conf
snort 13194 17.7 76.0  DLs  Tue12PM   0:47.26 snort -q -D -c snort.conf
snort 13194 17.2 75.7  DLs  Tue12PM   0:47.32 snort -q -D -c snort.conf
snort 13194 17.2 75.8  DLs  Tue12PM   0:47.41 snort -q -D -c snort.conf
snort 13194 16.9 75.7  DLs  Tue12PM   0:47.51 snort -q -D -c snort.conf
snort 13194 16.7 75.7  DLs  Tue12PM   0:47.60 snort -q -D -c snort.conf
snort 13194 16.3 75.8  DLs  Tue12PM   0:47.66 snort -q -D -c snort.conf
snort 13194 16.3 75.8  DLs  Tue12PM   0:47.74 snort -q -D -c snort.conf
snort 13194 16.1 75.8  DLs  Tue12PM   0:47.84 snort -q -D -c snort.conf
snort 13194 16.2 75.8  DLs  Tue12PM   0:47.92 snort -q -D -c snort.conf
snort 13194 16.2 75.7  DLs  Tue12PM   0:48.00 snort -q -D -c snort.conf
snort 13194 15.9 75.8  DLs  Tue12PM   0:48.10 snort -q -D -c snort.conf
snort 13194 15.7 75.8  DLs  Tue12PM   0:48.18 snort -q -D -c snort.conf
snort 13194 15.6 75.8  Rs   Tue12PM   0:48.27 snort -q -D -c snort.conf
snort 13194 15.6 75.7  DLs  Tue12PM   0:48.33 snort -q -D -c snort.conf
snort 13194 15.2 75.7  DLs  Tue12PM   0:48.40 snort -q -D -c snort.conf
snort 13194 14.9 75.9  DLs  Tue12PM   0:48.49 snort -q -D -c snort.conf
snort 13194 14.9 75.7  DLs  Tue12PM   0:48.55 snort -q -D -c snort.conf
snort 13194 14.8 75.9  DLs  Tue12PM   0:48.61 snort -q -D -c snort.conf
snort 13194 14.4 75.7  DLs  Tue12PM   0:48.66 snort -q -D -c snort.conf
snort 13194 14.4 75.6  DLs  Tue12PM   0:48.73 snort -q -D -c snort.conf
snort 13194 14.4 75.7  DLs  Tue12PM   0:48.78 snort -q -D -c snort.conf
snort 13194 14.1 75.8  DLs  Tue12PM   0:48.83 snort -q -D -c snort.conf

After ~60 seconds, pid 13194 finally terminate and snort exits.

S   Marks a process that is sleeping for less than about 20 seconds.
s   The process is a session leader.
D   Marks a process in disk (or other short term, uninterruptible) wait.
L   Marks a process that is waiting to acquire a lock.
R   Marks a runnable process.



The waiting after the statistics have been printed. Example:

...blah blah...
...blah blah...
         --== Initialization Complete ==--

    ,,_     -*> Snort! <*-
   o"  )~   Version 2.8.5.2 (Build 121)
    ''''    By Martin Roesch & The Snort Team: 
http://www.snort.org/snort/snort-team
            Copyright (C) 1998-2009 Sourcefire, Inc., et al.
            Using PCRE version: 8.00 2009-10-19

            Rules Engine: SF_SNORT_DETECTION_ENGINE  Version 1.11  <Build 
17>
            Preprocessor Object: SF_SSLPP  Version 1.1  <Build 3>
            Preprocessor Object: SF_SSH  Version 1.1  <Build 2>
            Preprocessor Object: SF_SMTP  Version 1.1  <Build 8>
            Preprocessor Object: SF_FTPTELNET  Version 1.2  <Build 12>
            Preprocessor Object: SF_DNS  Version 1.1  <Build 3>
            Preprocessor Object: SF_DCERPC2  Version 1.0  <Build 2>
            Preprocessor Object: SF_DCERPC  Version 1.1  <Build 5>
            Preprocessor Object: SF_Dynamic_Example_Preprocessor  Version 
1.0  <Build 1>
Not Using PCAP_FRAMES
^C*** Caught Int-Signal
Run time prior to being shutdown was 80.729902 seconds
===============================================================================
Packet Wire Totals:
    Received:          936
    Analyzed:          923 (98.611%)
...blah blah...
...blah blah...
===============================================================================
dcerpc2 Preprocessor Statistics
   Total sessions: 0
===============================================================================
===============================================================================
<<<<<<< here it hang for 60 seconds >>>>>>>
Snort exiting




If I have 12000 signatures, it hangs for 14 seconds before the process 
dies. If I add 1000 more signatures (13000 in total), it hangs for 34 
seconds. Yet another 1000 signatures = 62 seconds and so on...


/Elof






On Wed, 5 May 2010, Leon Ward wrote:

> This is likely a function of your syslogd (kindly trying to coalesce
> events for you), not Snort itself.
>
> Check the status of the pid via ps after sending it the TERM.
>
> -Leon
>
> On 3 May 2010 13:03,  <elof at ...969...> wrote:
>>
>> I run snort v2.8.5.2 as a daemon (chrooted, with different uid/gid and
>> with several output plugins activated, including database).
>>
>> When I run 'kill <pid>', I immediately get syslog messages indicating that
>> snort is going down (closing db connection, dumping stats, etc).
>>
>> However, the process don't die until 60 seconds later. See the
>> timestamps of the last two syslog rows:
>>
>>
>> May  3 13:48:05 snortbox snort[97227]:            UDP Port Filter
>> May  3 13:48:05 snortbox snort[97227]:                    Dropped: 0
>> May  3 13:48:05 snortbox snort[97227]:                  Inspected: 0
>> May  3 13:48:05 snortbox snort[97227]:                    Tracked: 0
>> May  3 13:48:05 snortbox snort[97227]: ==============================
>> May  3 13:48:05 snortbox snort[97227]: ==============================
>> May  3 13:48:05 snortbox snort[97227]: dcerpc2 Preprocessor Statistics
>> May  3 13:48:05 snortbox snort[97227]: ==============================
>> May  3 13:48:05 snortbox snort[97227]: ==============================
>> May  3 13:48:05 snortbox snort[97227]: Could not remove pid file
>> /var/run//snort_eth0.pid: No such file or directory
>> May  3 13:49:04 snortbox snort[97227]: Snort exiting
>>
>>
>> ------------------------------------------------------------------------------
>> _______________________________________________
>> Snort-devel mailing list
>> Snort-devel at lists.sourceforge.net
>> https://lists.sourceforge.net/lists/listinfo/snort-devel
>>
>


More information about the Snort-devel mailing list