Radium netflow collection: many records in the future?
Carter Bullard
carter at qosient.com
Tue Jul 23 12:46:31 EDT 2013
Hey Jesse,
I've added an error message when you fail to create the intended target file.
Not sure where that error message went, sorry for the inconvenience.
Here is a patch.
osiris:common carter$ diff ./common/argus_util.c.orig ./common/argus_util.c
25258c25258,25259
< }
---
> } else
> ArgusLog (LOG_ERR, "setArgusWfile open %s %s", file, strerror(errno));
Carter
On Jul 23, 2013, at 12:28 PM, Carter Bullard <carter at qosient.com> wrote:
> 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/0120e2a3/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/0120e2a3/attachment.bin>
More information about the argus
mailing list