Radium netflow collection: many records in the future?

Jesse Bowling jessebowling at gmail.com
Tue Jul 23 11:50:40 EDT 2013


So it looks like duration is either 0 or 300 (the time limit of my file
chunks) for the future records.

I'm trying to start a troubleshooting this looking at an hour's traffic at
a run using this simple script:

#!/bin/bash

if [ -f /netflow.troubleshoot.ra.pcap ]
then
  rm /netflow.troubleshoot.ra.pcap
fi


if [ -f /netflow.troubleshoot.ra.argus ]
then
  rm /netflow.troubleshoot.ra.argus
fi

/usr/sbin/tcpdump -i eth0 -nn -w /netflow.troubleshoot.ra.pcap -G 3600 -W 1
dst port 9996 &
time /usr/local/bin/ra -S localhost -T 3600 -w
/netflow.troubleshoot.ra.argus &

However the ra process dies after 16 seconds (consistently). Logs indicate
only:

Jul 23 11:42:42 localhost radium[5579]: 07/23/13 11:42:42.332615 connect
from localhost[127.0.0.1]
Jul 23 11:42:58 localhost radium[5579]: 07/23/13 11:42:58.618391
ArgusCheckClientMessage: client localhost[127.0.0.1] sent DONE

turning debug up to 6 gets me this at the end:

ra[6491.0047ed51d27f0000]: 07/23/13 11:45:27.821739 ArgusWriteNewLogfile
(/netflow.troubleshoot.ra.argus, 0x6e30c0) returning 0
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:27.821748 RaScheduleRecord
(0x7fd251e2f010, 0x7fd252164620) scheduled
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:27.821756 ArgusHandleDatum
(0x7fd251820a50, 0x7fd251eb0790) returning 112
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730108 ArgusClientTimeout()
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730165 ArgusShutDown (0)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730176 ArgusShutDown (0)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730184 RaParseComplete(caught
signal 0)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730195 ArgusFree (0x1c47190)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730203 ArgusDeleteQueue
(0x1c47190) returning
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730240
ArgusCloseInput(0x52164010) closing
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730251 ArgusWriteConnection:
write(3, 0x48b418, 6)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730321
ArgusWriteConnection(0x52164010, 0x48b418, 6) returning 6
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730716 ArgusFree
(0x7fd251820010)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730774 ArgusFree
(0x7fd2517df010)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730794
ArgusCloseInput(0x52164010) done
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730831 ArgusFree
(0x7fd252164010)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730854 ArgusFree (0x1c471e0)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730862 ArgusDeleteQueue
(0x1c471e0) returning
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730870 ArgusWindowClose ()
returning
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730885 RaParseComplete(caught
signal 0)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730894
ArgusReadStream(0x7fd251e2f010, 0x1c471e0) returning
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730904 RaParseComplete(caught
signal 0)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730912 ArgusShutDown (0)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730922 ArgusFree (0x1c47050)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730930 ArgusDeleteList
(0x1c47050, 4) returning
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730938 ArgusFree (0x1c470f0)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730946 ArgusDeleteList
(0x1c470f0, 4) returning
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730954 ArgusFree (0x1c494e0)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730961 ArgusFree (0x1c49400)
ra[6491.0047ed51d27f0000]: 07/23/13 11:45:28.730969 ArgusDeleteList
(0x1c49400, 2) returning


Oh the rabbit holes!

Cheers,

Jesse



On Tue, Jul 23, 2013 at 10:36 AM, Carter Bullard <carter at qosient.com> wrote:

> Hey Jesse,
> Each netflow packet contains multiple netflow records, and the time for
> all the flows in the packet is relative to a timestamp at the beginning of
> the packet.
> If chunks of netflow records are wrong, I'd want to say that we're not
> getting
> a good timestamp and its affecting blocks of data.  Of course, we could
> be not parsing the timestamp correctly, as well, but that is less
> attractive ;O)
>
> What are the durations of these flows?  "-s +1dur ".   We have to parse
> both
> a starting time and an ending time.
>
> It maybe useful to capture the netflow packet stream, with tcpdump, and
> double check that argus and wireshark agree.
>
> Also, do you get some records that look good, and then a chunk of flows
> that are off, then it goes back to being good?
>
> If you just attach to the radium with ra(), writing that to a file, we'll
> see what
> the actual netflow data stream, which may show this type of behavior ?
>
> Carter
>
> On Jul 23, 2013, at 9:36 AM, Jesse Bowling <jessebowling at gmail.com> wrote:
>
> Hi,
>
> I'm collecting neflow records with radium, using argus-clients 3.0.7.9.
> I've found that I have quite a few records that list start times in the
> future; sometimes two months in the future! I notice that almost all the
> records with future dates list a 5 minute boundary as the start time, i.e.:
>
> # ra -r argus.2013.09.10.00.00.00 -N 10 -w - - | ranonymize -r -
>                      StartTime      Flgs  Proto            SrcAddr
> Sport   Dir            DstAddr  Dport  TotPkts   TotBytes State
>       09/10/13 00:00:00.000000 Ne            17
> 1.0.2.1.54076     ->            1.0.3.1.63008        43      60370   REQ
>       09/10/13 00:00:00.000000 Ne             6
> 100.0.1.1.52469     ?>            1.0.4.1.53624         2       2551   INT
>       09/10/13 00:00:00.000000 Ne             6
> 100.0.1.1.52469     ?>            1.0.4.2.53359         2       2545   INT
>       09/10/13 00:00:00.000000 Ne             6
> 100.0.1.1.52469     ?>            1.0.4.3.53572         1       1275   INT
>       09/10/13 00:00:00.000000 Ne             6
> 100.0.1.1.52469     ?>            1.0.4.4.54880         2       2553   INT
>       09/10/13 00:00:00.000000 Ne             6
> 100.0.2.1.39995     ?>            1.0.5.1.59243         1         45   INT
>       09/10/13 00:00:00.000000 Ne             6
> 1.0.5.1.59243     ?>          100.0.2.1.39995         3       2700   INT
>       09/10/13 00:00:00.000000 Ne             6
> 100.0.3.1.54214     ?>          100.0.4.1.80           17        782   INT
>       09/10/13 00:00:00.000000 Ne             6
> 1.0.6.1.80        ?>          100.0.5.1.42526        36      51113   INT
>       09/10/13 00:00:00.000000 Ne             6
> 100.0.5.1.42526     ?>            1.0.6.1.80            6        349   INT
>
> Can anyone suggest a strategy for determining whether the fault lies
> within the argus processing, or the netflow generation?
>
> Thanks,
>
> Jesse
>
> $ grep -Ev '^#|^[ \t]*$' /etc/radium.conf
> RADIUM_DAEMON=yes
> RADIUM_MAR_STATUS_INTERVAL=60
> RADIUM_CISCONETFLOW_PORT=9996
> RADIUM_ACCESS_PORT=561
>
> $ grep -Ev '^#|^[ \t]*$' /etc/ra.conf
> RA_SET_PID="no"
> RA_PID_PATH="/var/run"
> RA_RUN_TIME=0
> RA_PRINT_MAN_RECORDS=no
> RA_PRINT_EVENT_RECORDS=yes
> RA_PRINT_LABELS=0
> RA_FIELD_SPECIFIER="stime:24 flgs proto saddr sport dir daddr dport pkts
> bytes state"
> RA_PRINT_NAMES=none
> RA_CIDR_ADDRESS_FORMAT="yes"
> RA_PRINT_RESPONSE_DATA=no
> RA_PRINT_UNIX_TIME=no
> RA_TIME_FORMAT="%D %T.%f"
> RA_USEC_PRECISION=6
> RA_USERDATA_ENCODE=Ascii
> RA_DELEGATED_IP="/usr/local/argus/delegated-ipv4-latest"
>
> Started with:
>
> /usr/local/bin/radium -f /etc/radium.conf
> /usr/local/bin/rasplit -M time 5m -S 127.0.0.1:561 -w
> /argus/netflow/%Y/%m/%d/argus.%Y.%m.%d.%H.%M.%S &
>
> Cheers,
>
> Jesse
>
> --
> Jesse Bowling
>
>
>


-- 
Jesse Bowling
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://pairlist1.pair.net/pipermail/argus/attachments/20130723/d551789d/attachment.html>


More information about the argus mailing list