Radium netflow collection: many records in the future?
Carter Bullard
carter at qosient.com
Tue Jul 23 12:28:28 EDT 2013
So, do something new, and you run into new things.
Looks like your trying to create and write into the file:
/netflow.troubleshoot.ra.argus
May want to put a dot in front, or take out the '/' ?
Carter
On Jul 23, 2013, at 11:50 AM, Jesse Bowling <jessebowling at gmail.com> wrote:
> 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/2fb6b453/attachment.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 6837 bytes
Desc: not available
URL: <https://pairlist1.pair.net/pipermail/argus/attachments/20130723/2fb6b453/attachment.bin>
More information about the argus
mailing list