argus 3.0 bloating on OpenBSD 4.3

[Carter Bullard]

>
> Hey Michael,
> Yes, I am working on a work around.
> Flows with time in the past should not be a problem, but time waaay  
> in the future will cause exactly the behavior you describe.  And it  
> is very difficult to decide as a piece of software, what is correct  
> time.
>
> If a record is put in the queue with a system time stamp way out,  
> when that record comes to end of the queue, which is a FIFO queue,  
> it will simple not consume any records until that time stamp  
> expires.  We still process packets, we just don't time the status  
> records out.
>
> When you kill argus gracefully, it will flush all the records that  
> are in the cache, so what you are seeing is by design.
>
> Carter
>
> Sent from my Verizon Wireless BlackBerry
>
> -----Original Message-----
> From: Michael Sanderson <sanders at cs.ubc.ca>
>
> Date: Mon, 26 Jan 2009 23:33:09
> To: <argus-info at lists.andrew.cmu.edu>
> Subject: [ARGUS] argus 3.0 bloating on OpenBSD 4.3
>
>
> I'm seeing similar things to what Martijn van Oosterhout had with his
> Linux machine, though on OpenBSD 4.3.
>
> I'm running argus 3.0 on a 32-bit OpenBSD 4.3 machine, with an ra
> collecting data on a 32-bit OpenSuSE box.  Neither is running a
> customized kernel.  Argus does not appear to be built with threads on
> the OpenBSD box.  Upon occassion, the argus will output error lines  
> like
>
> ArgusInterface timestamps wayyy out of order: now -732332471 then
> 1233017300
> ArgusInterface timestamps wayyy out of order: now -1504018871 then
> 1233017510
>
> and shortly after that it begins to bloat, while the data collector
> begins to receive less data.  The collector's rotated files are  
> smaller
> and traffic that I would expect to see in the files may not be  
> present,
> though there is some traffic.  All expected protocols are present, but
> definitely not all of the traffic.  Intriguingly, if the argus  
> daemon is
> 'kill'ed before the box runs out of memory, it will happily send all  
> of
> the flows to the collector before exiting.  Typically there is a
> seriously wacky date on one of the flows that is sent.
>
> As an example, the two entries above took place 26 Jan 09
> 16:48:20.937511 and 26 Jan 09 16:51:50.396118 (incidently, the first
> time I have see two close together like that).  I rotate every 15
> minutes and my file sizes look like:
>
> -rw-r--r-- 1 root root 11760560 2009-01-26 16:00
> data.2009.01.26-16:00:01
> -rw-r--r-- 1 root root 10244648 2009-01-26 16:15
> data.2009.01.26-16:15:01
> -rw-r--r-- 1 root root 10110680 2009-01-26 16:30
> data.2009.01.26-16:30:01
> -rw-r--r-- 1 root root 11347580 2009-01-26 16:45
> data.2009.01.26-16:45:02
> -rw-r--r-- 1 root root  4338192 2009-01-26 17:00
> data.2009.01.26-17:00:01
> -rw-r--r-- 1 root root  2136652 2009-01-26 17:15
> data.2009.01.26-17:15:01
> -rw-r--r-- 1 root root  2043564 2009-01-26 17:30
> data.2009.01.26-17:30:01
> -rw-r--r-- 1 root root  2082432 2009-01-26 17:45
> data.2009.01.26-17:45:01
>
> The kill took place between 21:45 and 22:00:
>
> -rw-r--r-- 1 root root  2191072 2009-01-26 21:45
> data.2009.01.26-21:45:01
> -rw-r--r-- 1 root root 94159604 2009-01-26 22:00
> data.2009.01.26-22:00:01
>
> Here is a segment of the output from an ra on data.2009.01.26-22:00:01
> (sorry for line wrapping).  Note the 46/10/17 date on the fourth  
> output
> line.
>
> 09/01/26 21:01:27  e         udp      77.85.162.112.27371    <->
> 142.103.17.161.19164         2        463   CON
>
> 09/01/26 21:47:06  e         tcp       86.96.229.89.14410     ->
> 142.103.6.5.80            2        114   FIN
>
> 09/01/26 21:46:58  e         udp      137.82.37.253.32770    <->
> 198.162.63.42.161           6       2133   CON
>
> 09/01/26 20:17:50  e         tcp      142.103.9.193.37207     ->
> 75.126.170.58.443          16       3299   RST
>
> 46/10/17 14:18:49  e         tcp      142.103.17.80.59990     ->
> 212.187.172.5.23456        11        820   FIN
>
> 09/01/26 16:48:20  e         udp        142.103.6.6.51948    <->
> 204.13.250.26.53            2        266   CON
>
> 09/01/26 16:48:20  e         tcp     142.103.15.108.3004      ->
> 128.121.146.100.443          14       3660   RST
>
> 09/01/26 16:48:20  e         udp      200.63.155.21.43823    <->
> 198.162.35.1.53            2        214   CON
>
> 09/01/26 16:48:20  e         tcp       60.173.11.39.14400     ->
> 142.103.23.48.1234          1         58   ACC
>
> Another note of interest in the output is that the timestamps jump all
> over the place prior to the wacky date, with lines from as early as
> 09/01/26 16:55:43 (shortly after the error message) through to current
> time.  After the wacky date is output, the dates appear to
> chronologically increase.  It MAY be that the wacky date corresponds  
> to
> when the kill was issued.  I'll have to try watching a data stream the
> next time I do a kill.
>
> Is anyone aware of an OpenBSD 4.3 time error along the lines of the
> Linux kernel bug that affected Martijn's configuration?  Carter, there
> had been a bit of discussion on the list about mitigating these
> effects.  Is this something that you have looked at?
>
>    Michael Sanderson
>
>
>