Re: Bugreport - 60 second timeout before shutdown

[Steven Sturges <steve.sturges () sourcefire com>]

There is alot more happening during termination of Snort now then
what used to.

Because of the improved ability to reload configurations without
termination (added in 2.8.5), this shouldn't be as much of an issue.
To prevent memory leaks, Snort is cleaning up alot of memory when a
configuration is reloaded, and that happens as well at shutdown.

Previously, all of the memory allocated over the life of Snort was
just left dangling.  And while it would typically be cleaned up by
the OS when the process terminated, that memory includes TCP session
data for which there are outstanding TCP reassemblies to be done.
So Snort is performing those TCP reassemblies at shutdown and inspecting
that reassembled traffic, which is why you may see alerts after the
shutdown is initiated and things take a little longer than before.

Cheers.
-steve

Jason Wallace wrote:
> I noticed this a while back. Just assumed it was normal behavior. I
> added a pause to the init.d script when shutting down to work around
> it.
>
> Wally
>
> On Thu, May 6, 2010 at 8:36 AM,  <elof () sentor se> wrote:
> > 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 () sentor se> 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 () lists sourceforge net
> > > > https://lists.sourceforge.net/lists/listinfo/snort-devel
> > ------------------------------------------------------------------------------
> >
> > _______________________________________________
> > Snort-devel mailing list
> > Snort-devel () lists sourceforge net
> > https://lists.sourceforge.net/lists/listinfo/snort-devel
>
> ------------------------------------------------------------------------------
> _______________________________________________
> Snort-devel mailing list
> Snort-devel () lists sourceforge net
> https://lists.sourceforge.net/lists/listinfo/snort-devel

------------------------------------------------------------------------------
_______________________________________________
Snort-devel mailing list
Snort-devel () lists sourceforge net
https://lists.sourceforge.net/lists/listinfo/snort-devel