argus crash problem

Carter Bullard carter at qosient.com
Wed Jan 30 22:34:50 EST 2008


You should read the man pages for the programs you are running.
Read how to print fields using ra().  If you are only capturing one
part of the link, then the '?' are normal.  If not, then maybe not,
depending on how routing is setup in your environment.

Carter


On Jan 30, 2008, at 6:30 PM, Lei Wei wrote:

> Hi Carter,
>
> I'll do what you suggested. But I don't quite understand "You should  
> print both spkts and dpkts". what does "spkts" mean and How do I do  
> that?  And by the way, is it normal that I got so many connections  
> with unknown directions?
>
> Thanks.
> Lei
>
>
>
> Quoting Carter Bullard <carter at qosient.com>:
>
>> Hey Lei,
>> You should print both spkts and dpkts, so you can see if you're   
>> getting full-duplex
>> flow monitoring.  Running with debug information is probably not  
>> going  to
>> shed any light on the problem you ran into.   Run without the  
>> option  to see
>> how argus performs on your system.  Depending on the type of dag  
>> card,  you
>> could saturate the BUS around 2Gbps.  If you have the the PCI  
>> express  cards,
>> you still may not get  10Gbps, depending on the motherboard you  
>> are  using.
>>
>> Just run without the "-D" option for a while to see if you get the  
>> bug  again.
>> Also try modifying the flow model using the /etc/argus.conf file  
>> to  see if
>> you can get the pcu utilization down.
>>
>> Carter
>>
>>
>> On Jan 30, 2008, at 5:25 PM, Lei Wei wrote:
>>
>>> You are right. I took a look at the flow. I could see some full  
>>> tcp  connections,i.e.from REQ,CON to FIN. But it seems that many   
>>> connections have unknown directions like below. Is that normal?
>>>
>>> 15:58:19.299491  e            tcp     208.107.16.125.2740     <?  
>>> >     152.23.105.115.6881          2        121   CON
>>> 15:58:19.299491  e         udp     128.109.230.21.10002     -  
>>> >       233.4.200.18.10002         2        136   INT
>>> 15:58:19.299511  e         udp     155.101.127.30.10002     -  
>>> >       233.4.200.18.10002         3        204   INT
>>> 15:58:19.299539  e s       tcp     207.251.97.202.54174    <?  
>>> >        152.2.2.149.smtp         26      22585   CON
>>> 15:58:19.299551  e         udp     90.196.179.159.5331     <- 
>>> >      152.23.124.201.9965          7       4216   CON
>>> 15:58:19.299616  e         udp        152.2.122.3.1179      - 
>>> >       118.170.8.216.64371         9        563   INT
>>> 15:58:19.299618  e         tcp      81.52.130.186.http     <? 
>>> >      152.23.110.254.2068         10       9275   CON
>>> 15:58:19.299634  e         tcp     152.23.211.119.52335    <? 
>>> >       59.134.50.151.3830          3       1412   CON
>>> 15:58:19.299663  e s       tcp     76.182.114.156.2093     <?  
>>> >       152.2.210.22.rdp           6        558   CON
>>> 15:58:19.299676  e         tcp      66.249.93.109.imaps    <?  
>>> >       152.23.88.57.1055          3        263   CON
>>> 15:58:19.299677  e s       tcp        74.125.1.81.http     <?  
>>> >       152.2.176.13.3282         63      64848   CON
>>> 15:58:19.299690  e         tcp       152.2.62.113.here-l   <?  
>>> >       204.10.66.76.http         12       7402   CON
>>> 15:58:19.299690  e         tcp      90.198.223.64.2684      ? 
>>> >       152.23.79.176.16328         2       3028   CON
>>> 15:58:19.299739  e         tcp     63.146.183.217.http     <? 
>>> >      204.85.193.203.16244        43      37784   CON
>>> 15:58:19.299778  e         tcp      64.233.179.91.http      ? 
>>> >       152.23.93.163.4708          2       2968   CON
>>> 15:58:19.299804  e         tcp         152.2.1.95.smtp     <?  
>>> >        62.43.82.68.50100         6       2096   CON
>>> 15:58:19.299823  e         tcp      81.52.130.152.http      ? 
>>> >       152.23.69.105.1232          1         60   CON
>>> 15:58:19.299862  e         tcp     195.241.129.86.14816    <?  
>>> >        152.2.32.11.53759        67      25519   CON
>>> 15:58:19.299891  e         tcp     81.154.227.107.51157    <? 
>>> >      152.23.126.198.12215         3       1834   CON
>>> 15:58:19.299892  e d       tcp     208.253.91.250.40767    <?  
>>> >        152.2.63.68.rtsp         17       7464   CON
>>> 15:58:19.299893  e         tcp      84.67.187.146.52319    <? 
>>> >       152.23.63.139.2077          5       3206   CON
>>> 15:58:19.299893  e         tcp    124.121.160.139.16800    <? 
>>> >      152.23.204.249.4173          2       1560   CON
>>> 15:58:19.299928  e         udp      152.2.255.242.10000    <-  
>>> >       76.182.85.17.10000       114      94428   CON
>>> 15:58:19.299938  e         tcp       152.23.69.88.3038     <? 
>>> >       206.33.52.123.http         68      68056   CON
>>>
>>>
>>>
>>>
>>> Quoting Carter Bullard <carter at qosient.com>:
>>>
>>>> One important question is whether the flows look reasonable.
>>>> Full tcp connections, bidirectional etc...
>>>> Carter
>>>>
>>>> On Jan 30, 2008, at 3:57 PM, Lei Wei wrote:
>>>>
>>>>> Argus didn't stop since the file is still growing and the  
>>>>> memory   usage showing in top is about 493mb. Since you  
>>>>> mentioned that  argus  slows down when it's in debug mode, does  
>>>>> it mean that it  might drop  some packets when running?
>>>>>
>>>>> It's a little bit wierd because when I asked it to output the   
>>>>> debug  info to the stdout, it outputs many just like you did.   
>>>>> But  when I  tried to redirect it to write into a file using  
>>>>> "argus -i  dag0 -w  data.out -D 2 > error 2>&1 ", it only  
>>>>> outputs several  lines into the  file:
>>>>>
>>>>> argus[574]: 28 Jan 08 01:14:13.680343 ArgusNewModeler()  
>>>>> returning   0x816f000
>>>>> argus[574]: 28 Jan 08 01:14:13.686915 ArgusNewSource()  
>>>>> returning   0x81b2000
>>>>> argus[574]: 28 Jan 08 01:14:13.686963 ArgusNewOutput()  
>>>>> returning   retn 0x81b1100
>>>>> argus[574]: 28 Jan 08 01:14:13.708239 setArgusID(0x816f000,    
>>>>> 0x9802899f) done
>>>>> argus[574]: 28 Jan 08 01:14:13.708311 setArgusPortNum(561)  
>>>>> returning
>>>>> argus[574]: 28 Jan 08 01:14:13.708512 setArgusInterfaceStatus(1)
>>>>>
>>>>> I guess maybe I should run it again and just let it output the   
>>>>> debug  info on the screen and see what it'll happen.
>>>>>
>>>>> Lei
>>>>>
>>>>>
>>>>> Quoting Peter Van Epp <vanepp at sfu.ca>:
>>>>>
>>>>>> On Wed, Jan 30, 2008 at 01:45:17PM -0500, Lei Wei wrote:
>>>>>>> Hello Peter and Carter,
>>>>>>>
>>>>>>> I've been trying to repeat the crash problem again recently. I  
>>>>>>> ran
>>>>>>> argus with the debug option enabled from Sunday night until  
>>>>>>> now.  It
>>>>>>> never crashed. The only debug information it outputed was   
>>>>>>> several  lines
>>>>>>> when argus started to run and nothing more. The CPU usage  
>>>>>>> right   now is
>>>>>>> till about 99% but the output data file grows well and now is   
>>>>>>> about
>>>>>>> 144G already. I'm not sure why I can't repeat the crash again   
>>>>>>> and  there
>>>>>>> shouldn't be too much difference in the amount of traffic   
>>>>>>> between  this
>>>>>>> and last week. By the way, the link I'm monitoring is the   
>>>>>>> campus  border
>>>>>>> link to the ISP and the traffic load is more than 1G per   
>>>>>>> second.  I
>>>>>>> wonder if there's any difference running in debug mode that  
>>>>>>> could
>>>>>>> possibly play a role in it...  Anyway, I'll keep monitoring  
>>>>>>> it  and  see
>>>>>>> what happens.
>>>>>>>
>>>>>>> Lei
>>>>>>>
>>>>>>
>>>>>> 	Hmmm, thats too bad. Debug mode does slow argus down a bit, its
>>>>>> possible that its slowing it down enough that the problem  
>>>>>> isn't   happening.
>>>>>> What does memory usage look like? I'd be suspicious that what  
>>>>>> is   happening
>>>>>> is that argus is running out of memory and stopping (although   
>>>>>> that  should
>>>>>> show up in syslog). That said I just noticed I'm not getting  
>>>>>> any   syslog
>>>>>> messages from argus (and I think I should be). I just  
>>>>>> restarted  one  of my
>>>>>> test ones with -D2:
>>>>>>
>>>>>> # argus -J -P 560 -i eth2 -i eth3 -m -U700 -D2  -- host    
>>>>>> 142.58.101.100
>>>>>> argus[4637]: 30 Jan 08 12:32:05.555408 ArgusNewModeler()   
>>>>>> returning  0x10181010
>>>>>> argus[4637]: 30 Jan 08 12:32:05.555871 ArgusNewSource()   
>>>>>> returning  0x10201f70
>>>>>> argus[4637]: 30 Jan 08 12:32:05.555903 ArgusNewOutput()   
>>>>>> returning  retn 0x102016b0
>>>>>> argus[4637]: 30 Jan 08 12:32:05.555985 setArgusPortNum(560)   
>>>>>> returning
>>>>>> argus[4637]: 30 Jan 08 12:32:05.556023 setArgusInterfaceStatus(1)
>>>>>> argus[4637]: 30 Jan 08 12:32:05.585055 ArgusInitSource()    
>>>>>> pcap_open_live(eth3) returned 0x10252d60
>>>>>> argus[4637]: 30 Jan 08 12:32:05.585119    
>>>>>> ArgusOpenInterface(0x10201f70, 'eth3') returning
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615008 ArgusInitSource()    
>>>>>> pcap_open_live(eth2) returned 0x10253370
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615071    
>>>>>> ArgusOpenInterface(0x10201f70, 'eth2') returning
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615119  
>>>>>> ArgusCopyArgv(0xff8811f8)   returning 0x10253980
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615298 ArgusInitSource()  
>>>>>> returning
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615357  
>>>>>> ArgusEstablishListen(560,   (null), 0xff880a18)
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615526  
>>>>>> ArgusEstablishListen(560,   0xff880a18) binding: any:560
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615607  
>>>>>> ArgusEstablishListen(560,   0xff880a18) returning 5
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615633 ArgusInitOutput() done
>>>>>> ArgusWarning: argus[4637]: 30 Jan 08 12:32:05.615670 started
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615711 ArgusInitModeler() done
>>>>>> argus[4637]: 30 Jan 08 12:32:05.615974 setArgusInterfaceStatus(1)
>>>>>> ArgusWarning: argus[4637]: 30 Jan 08 12:32:05.616010    
>>>>>> ArgusGetInterfaceStatus: interface eth3 is up
>>>>>> argus[4637]: 30 Jan 08 12:32:05.616046 setArgusInterfaceStatus(1)
>>>>>> ArgusWarning: argus[4637]: 30 Jan 08 12:32:05.616102    
>>>>>> ArgusGetInterfaceStatus: interface eth2 is up
>>>>>> argus[4637]: 30 Jan 08 12:32:05.616133 setArgusInterfaceStatus(1)
>>>>>> argus[4637]: 30 Jan 08 12:32:05.616159 setArgusInterfaceStatus(1)
>>>>>> argus[4637]: 30 Jan 08 12:32:59.824738 ArgusScheduleShutDown(2)
>>>>>>
>>>>>> argus[4637]: 30 Jan 08 12:32:59.824838 ArgusShutDown(Normal   
>>>>>> Shutdown)
>>>>>>
>>>>>> argus[4637]: 30 Jan 08 12:32:59.824856   
>>>>>> ArgusCloseSource(0x10201f70)  starting
>>>>>> argus[4637]: 30 Jan 08 12:32:59.824874   
>>>>>> ArgusCloseSource(0x10201f70)  deleting source
>>>>>> argus[4637]: 30 Jan 08 12:32:59.825600    
>>>>>> ArgusCloseModeler(0x10181010) pushing close record 0x1028f2b0
>>>>>> argus[4637]: 30 Jan 08 12:32:59.825625   
>>>>>> ArgusCloseModeler(0x10181010)
>>>>>> argus[4637]: 30 Jan 08 12:32:59.825642 ArgusCloseOutput()    
>>>>>> scheduling closure after writing records
>>>>>> argus[4637]: 30 Jan 08 12:32:59.825698 ArgusOutputProcess()    
>>>>>> received stop record 0 records on the list
>>>>>> argus[4637]: 30 Jan 08 12:32:59.825716   
>>>>>> ArgusCloseOutput(0x102016b0)  done
>>>>>> argus[4637]: 30 Jan 08 12:32:59.825759 ArgusShutDown()
>>>>>>
>>>>>> # tail /var/log/messages
>>>>>> ...
>>>>>> Jan 30 12:32:05 sniffer1 kernel: RING: succesfully allocated 0   
>>>>>> KB  [tot_mem=12664896][order=12]
>>>>>> Jan 30 12:32:05 sniffer1 kernel: RING: allocated 10851 slots    
>>>>>> [slot_len=1546][tot_mem=16777216]
>>>>>> Jan 30 12:32:05 sniffer1 kernel: RING: succesfully allocated 0   
>>>>>> KB  [tot_mem=12664896][order=12]
>>>>>> Jan 30 12:32:05 sniffer1 kernel: RING: allocated 10851 slots    
>>>>>> [slot_len=1546][tot_mem=16777216]
>>>>>>
>>>>>> 	and all that shows in syslog is the ring buffer starting as the
>>>>>> interfaces come up. I think argus used to syslog the  
>>>>>> interfaces   opening to
>>>>>> syslog which may mean there is a bug in syslogging.
>>>>>>
>>>>>> Peter Van Epp / Operations and Technical Support
>>>>>> Simon Fraser University, Burnaby, B.C. Canada
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>
>>>
>>>
>>>
>>
>
>
>



More information about the argus mailing list