[ARGUS] BSD argus/Linux ra problems?

[Michael Sanderson]

Peter Van Epp wrote:


> 	Touching ./devel and ./debug in the argus-clients source directory and
> doing ./config make would be interesting.

.devel and .debug for anyone that reads this later.

> Then starting ra with 
> 
> ra -D 8 -S server -w /tmp/t  
> 
> will dump debugging information to the console and may provide a clue about 
> what is wrong.

The plot thickens.  ra -D 8 -S ... runs.  -D 1 through -D 4 don't work. 
  -D 5 through -D 8 work (run multiple times) when at the shell.  When 
running under gdb, only -D 8 would work.  Here is output from the -D 4 
and -D 5 runs.

% bin/ra -D 4 -S daemon -w /tmp/t
ra[7467]: 22 Nov 04 01:33:12 ArgusCalloc (1, 496) returning 0x93f69dc
ra[7467]: 22 Nov 04 01:33:12 ArgusAddHostList (fw, 1) returning 1
ra[7467]: 22 Nov 04 01:33:12 ArgusDeleteList (0x0) returning
ra[7467]: 22 Nov 04 01:33:12 ArgusCalloc (1, 24) returning 0x93f6bec
ra[7467]: 22 Nov 04 01:33:12 ArgusNewList () returning 0x93f6bec
ra[7467]: 22 Nov 04 01:33:12 ArgusCalloc (1, 112) returning 0x93f6c0c
ra[7467]: 22 Nov 04 01:33:12 ArgusCalloc (1, 12) returning 0x93f6c84
ra[7469]: 22 Nov 04 01:33:12 ArgusFilterCompile () returning
ra[7467]: 22 Nov 04 01:33:12 ArgusFilterCompile () waiting for filter 
process 7469 on pipe 3
ra[7467]: 22 Nov 04 01:33:12 ArgusFilterCompile () read filter length 1
ra[7467]: 22 Nov 04 01:33:12 ArgusFilterCompile () read filter body 8
ra[7467]: 22 Nov 04 01:33:12 ArgusFilterCompile () returning 0
ra[7467]: 22 Nov 04 01:33:12 Trying fw.cs.ubc.ca port 561 Expecting 
Argus records
ra[7467]: 22 Nov 04 01:33:12 connected
ra[7467]: 22 Nov 04 01:33:12 ArgusGetServerSocket (0x93f69dc) returning 3
ra[7467]: 22 Nov 04 01:33:12 ArgusReadConnection() read failed for 
ARGUS_START Mar Success.
ra[7467]: 22 Nov 04 01:33:12 ArgusReadStream() ArgusRemoteFDs is empty
ra[7467]: 22 Nov 04 01:33:12 ArgusShutDown (0)


% bin/ra -D 5 -S daemon -w /tmp/t
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 496) returning 0x8bf69dc
ra[7475]: 22 Nov 04 01:33:19 ArgusAddHostList (fw, 1) returning 1
ra[7475]: 22 Nov 04 01:33:19 ArgusDeleteList (0x0) returning
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 24) returning 0x8bf6bec
ra[7475]: 22 Nov 04 01:33:19 ArgusNewList () returning 0x8bf6bec
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 112) returning 0x8bf6c0c
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 12) returning 0x8bf6c84
ra[7476]: 22 Nov 04 01:33:19 ArgusFilterCompile () returning
ra[7475]: 22 Nov 04 01:33:19 ArgusFilterCompile () waiting for filter 
process 7476 on pipe 3
ra[7475]: 22 Nov 04 01:33:19 ArgusFilterCompile () read filter length 1
ra[7475]: 22 Nov 04 01:33:19 ArgusFilterCompile () read filter body 8
ra[7475]: 22 Nov 04 01:33:19 ArgusFilterCompile () returning 0
ra[7475]: 22 Nov 04 01:33:19 Trying fw.cs.ubc.ca port 561 Expecting 
Argus records
ra[7475]: 22 Nov 04 01:33:19 connected
ra[7475]: 22 Nov 04 01:33:19 ArgusGetServerSocket (0x8bf69dc) returning 3
ra[7475]: 22 Nov 04 01:33:19 ArgusReadConnection() read 16 bytes
ra[7475]: 22 Nov 04 01:33:19 ArgusReadConnection() ARGUS_START Mar.
ra[7475]: 22 Nov 04 01:33:19 ArgusFree (0x8bf6c84) returning
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 12) returning 0x8bf6c84
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 4096) returning 0x8bf7544
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 4096) returning 0x8bf854c
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 4096) returning 0x8bf9554
ra[7475]: 22 Nov 04 01:33:19 ArgusParseInit (0x8bf69dc) returning
ra[7475]: 22 Nov 04 01:33:19 ArgusReadConnection() returning 3
ra[7475]: 22 Nov 04 01:33:19 ArgusReadStream() starting
ra[7475]: 22 Nov 04 01:33:19 ArgusWriteNewLogFile (/tmp/t, 0x807a2e0) 
bytes 88 returning 0
ra[7475]: 22 Nov 04 01:33:19 ArgusFree (0x8bf6c84) returning
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 12) returning 0x8bf6c84
ra[7475]: 22 Nov 04 01:33:19 ArgusWriteNewLogFile (/tmp/t, 0x807a2e0) 
bytes 88 returning 0
ra[7475]: 22 Nov 04 01:33:19 ArgusFree (0x8bf6c84) returning
ra[7475]: 22 Nov 04 01:33:19 ArgusCalloc (1, 12) returning 0x8bf6c84
ra[7475]: 22 Nov 04 01:33:19 ArgusWriteNewLogFile (/tmp/t, 0x807a2e0) 
bytes 88 returning 0
ra[7475]: 22 Nov 04 01:33:19 ArgusFree (0x8bf6c84) returning

Here is a tcpdump of the connection from the FC2 box (client) to the 
OpenBSD argus daemon (daemon).  The timing of the 'F' (presumably FIN) 
seems rather odd here.  It looks like it is closing the socket before it 
gets the first packet back from the daemon and then sends the expected 
RST!?!!?

02:04:16.223086 IP client.33327 > daemon.561: S 1407606257:1407606257(0) 
win 5840 <mss 1460,sackOK,timestamp 567400807 0,nop,wscale 7>
02:04:16.223214 IP daemon.561 > client.33327: S 1402344571:1402344571(0) 
ack 1407606258 win 16384 <mss 1460,nop,nop,sackOK,nop,wscale 
0,nop,nop,timestamp 1808318006 567400807>
02:04:16.223236 IP client.33327 > daemon.561: . ack 1 win 46 
<nop,nop,timestamp 567400807 1808318006>
02:04:16.224351 IP daemon.561 > client.33327: . 1:47(46) ack 1 win 17376 
<nop,nop,timestamp 1808318006 567400807>
02:04:16.224424 IP client.33327 > daemon.561: . ack 47 win 46 
<nop,nop,timestamp 567400808 1808318006>
02:04:16.224477 IP client.33327 > daemon.561: F 1:1(0) ack 47 win 46 
<nop,nop,timestamp 567400808 1808318006>
02:04:16.224558 IP daemon.561 > client.33327: P 47:129(82) ack 1 win 
17376 <nop,nop,timestamp 1808318006 567400808>
02:04:16.224584 IP client.33327 > daemon.561: R 1407606258:1407606258(0) 
win 0
02:04:16.224593 IP daemon.561 > client.33327: . ack 2 win 17376 
<nop,nop,timestamp 1808318006 567400808>
02:04:16.224601 IP client.33327 > daemon.561: R 1407606259:1407606259(0) 
win 0

With the -D 5 you don't see the FIN until the end, when you would expect it.

As another note, ra on Solaris 9 on an UltraSPARC IIIi compiled with 
-mcpu=v9 -m32 as additional CFLAGS reads happily (no .debug or .devel) 
from the OpenBSD argus daemon as well as a SuSE argus daemon.

Mike Slifcak, I will try your patch to see if anything changes.

      Michael Sanderson