Rastrip problems. [Was: Re: new clients rc.58 on the server]

[Patrick Forsberg]

Patrick Forsberg wrote:
> Carter Bullard wrote:
>> Gentle people,
>> ftp://qosient.com/dev/argus-3.0/argus-clients-3.0.0.rc.58.tar.gz
> 
>> If anyone finds any issues, regardless of wether its code, installation
>> problems, documentation errors, etc....   please send email!!!!!
> 
> 
> It would seem that rastrip is still broken
> 
> We collect argusdata on two nodes with two NICs each (IN and OUT).
> We collect 12 bytes of user DATA.
> We merge the data from the two nodes with racluster
> 
> Because of policy we need to clean out userdata after a period of time,
> but right now we don't trust rastrip since it looks as if it does things
> with the data that it shouldn't
> 
> Here's a representation of the problem:
> 
> #Sort the indata (since it comes from more than one collector)
> rasort -r /var/log/argus/2007/10/03-0000 -w 100300.rasort
> #Strip userdata from logfiles
> rastrip -M -suser -M -duser -r 100300.rasort -w 100300.rasort.strip1
> #Strip userdata again (should do nothing)
> rastrip -M -suser -M -duser -r 100300.rasort.strip1 -w 100300.rasort.strip2
> #Plaintext the stripped files
> ra -r 100300.rasort.strip1 >strip1
> ra -r 100300.rasort.strip2 >strip2
> 
> # I would expect the second run of rastrip to do nothing to the data since the
> # only thing it's supposed to do is remove suser and duser and that should
> # already be gone. But a simple comparison of the text output shows that
> # something funky is happening to some of the flows.
> 
> #Compare the two plaintext files. There should be no difference.
> diff strip1 strip2
> 10703c10703
> <    23:55:11.467660            tcp     1.2.3.4.63212     ->       2.3.4.5.smtp          1        2           68          198   RST
> ---
>>    23:54:59.085949            tcp     1.2.3.4.63212     ->       2.3.4.5.smtp          1        2           68          198   RST
> 10760c10760
> <    23:55:11.579806    d       tcp      3.4.5.6.55954     ->      2.3.4.6.smtp          1        1           60           60   RST
> ---
>>    23:54:58.833879    d       tcp      3.4.5.6.55954     ->      2.3.4.6.smtp          1        1           60           60   RST
> 19540c19540
> <    23:55:29.428842    d       tcp    4.5.6.7.3014      ->       2.3.4.7.http          7       12          426        15047   FIN
> ---
>>    23:54:57.897868    d       tcp    4.5.6.7.3014      ->       2.3.4.7.http          7       12          426        15047   FIN
> 23914c23914
> <    23:55:37.793078  e         tcp    5.6.7.8.42565     ->      2.3.4.8.http          3        4          192          264   RST
> ---
>>    23:55:09.038700  e         tcp    5.6.7.8.42565     ->      2.3.4.8.http          3        4          192          264   RST
> 
> <REST OF DATA STRIPPED>
> 
> 
> Only 24 out of 121773 flows are affected, but that's bad enough.

Further digging shows that rastrip has got nothing to do with the problem

I'll just extract one of the iffy records above and show by example:

# ra -r /var/log/argus/2007/10/03-0000 -w res1.ra - src host 1.2.3.4 and src port 63212
# ra -r res1.ra -w res2.ra
# ra -r res2.ra -w res3.ra
# ra  -s+ltime -r res1.ra
02 Oct 2007 23:54:59.085949            tcp     1.2.3.4.63212     ->       2.3.4.5.smtp          1        2           68          198   RST 02 Oct 2007 23:55:11.467660
# ra  -s+ltime -r res2.ra
02 Oct 2007 23:55:11.467660            tcp     1.2.3.4.63212     ->       2.3.4.5.smtp          1        2           68          198   RST 02 Oct 2007 23:54:59.085949
# /ra  -s+ltime -r res3.ra
02 Oct 2007 23:54:59.085949            tcp     1.2.3.4.63212     ->       2.3.4.5.smtp          1        2           68          198   RST 02 Oct 2007 23:55:11.467660

As you can see ra flips record start time and record last time between consecutive runs.

/Patrick