Argus on Bivio 7500
Peter Van Epp
vanepp at sfu.ca
Tue Aug 11 18:38:14 EDT 2009
On Tue, Aug 11, 2009 at 10:36:03AM -0400, Carter Bullard wrote:
> Hey Peter,
> Its possible the routine ArgusGetInterfaceStatus(), called from
> ArgusGetPackets(), around
> line 2044, which does some interface housekeeping, is broken on the
> Bivio and maybe closing
> the pcap interfaces?
>
> Carter
>
Yes that looks like a good possibility. While looking back at the
messages I came across this trace that Jason did. It does look like the
interface may have gotten closed (silently!) at around line 2500. If the
ioctl fails the interface will be quietly closed which would cause the
problem we are seeing later in the trace (no open interface as found never
gets incremented). I expect Jason needs to trace in to the call at line 2019
and we would probably be wise to add an ARGUSDEBUG statement or two to
ArgusGetInterfaceStatus such as:
line 2476:
if (device == NULL) {
#ifdef ARGUSDEBUG
ArgusDebug (4,"ArgusGetInterfaceStatus: device NULL returning\n";)
#endif
return;
}
line 2503:
src->ArgusInterface[i].ArgusPD = NULL;
#ifdef ARGUSDEBUG
ArgusDebug (4,"ArgusGetInterfaceStatus: interface %d closed, returning\n",i;)
#endif
I suspect we will find the last one is what is tripping us up this
time. That ioctl is reacting badly on the Bivio perhaps. It would also be
worthwhile doing a tail on /var/log/messages (assuming this is Linux) as a
number of errors syslog but don't ARGUSDEBUG log and one of them may provide
the necessary clue.
On Mon, Aug 10, 2009 at 11:17:36AM -0400, Jason Carr wrote:
> I've attached the gdb output and the configure log. It looks like
> pcap_get_selectable_fd is not available.
>
> The gdb log doesn't seem indicate that it even touched pcap_dispatch.
>
<snip>
> Starting program: /usr/local/sbin/argus -U 128 -i default -P 563 -e 1 -B 0.0.0.0 -D 999
> Reading symbols from shared object read from target memory...done.
> Loaded system supplied DSO at 0x100000
<snip>
As before it seems to open default successfully:
> argus[5858]: 10 Aug 09 11:13:11.782693 ArgusOpenInterface() pcap_open_live(default) returned 0x1012f590
> argus[5858]: 10 Aug 09 11:13:11.782790 Arguslookup_pcap_callback(1) returning 0x1000e940
> argus[5858]: 10 Aug 09 11:13:11.782835 ArgusOpenInterface(0x30070008, 'default') returning
<snip>
And we start to try and read packets from the interface but nowhere
does found get incremented which will result in the break at line 2239
to execute and ezit exactly as we are seeing. This in turn could well be
because the pcap interface was quietly closed earlier.
>
> Breakpoint 1, ArgusGetPackets (src=0x30070008) at ArgusSource.c:2000
> 2000 if (src != NULL) {
> (gdb) next
> 2002 ArgusDebug (4, "ArgusGetPackets (0x%x) starting\n", src);
> (gdb)
> 2022 for (i = 0; i < src->ArgusInterfaces; i++) {
> (gdb)
> 2002 ArgusDebug (4, "ArgusGetPackets (0x%x) starting\n", src);
> (gdb)
> argus[5858]: 10 Aug 09 11:13:15.638386 ArgusGetPackets (0x30070008) starting
> 2006 fds[i] = -1;
> (gdb)
> 2011 signal (SIGPIPE, SIG_IGN);
> (gdb)
> 2006 fds[i] = -1;
> (gdb)
> 2011 signal (SIGPIPE, SIG_IGN);
> (gdb)
> 0x1004fe20 in call___do_global_ctors_aux ()
> (gdb)
> Single stepping until exit from function call___do_global_ctors_aux,
>
> which has no line number information.
> 0x0fd6c8d0 in ssignal () from /lib/libc.so.6
> (gdb)
> Single stepping until exit from function ssignal,
> which has no line number information.
> ArgusGetPackets (src=0x30070008) at ArgusSource.c:2019
> 2019 ArgusGetInterfaceStatus(src);
> (gdb)
> argus[5858]: 10 Aug 09 11:13:17.669976 ArgusPopFrontList (0x1012dd98) returning
> argus[5858]: 10 Aug 09 11:13:17.670051 ArgusPushFrontList (0x1012dd68, 0x1012dd98, 1) returning 0xd032
> 2020 gettimeofday (&src->ArgusStartTime, 0L);
> (gdb)
> 0x10050340 in call___do_global_ctors_aux ()
> (gdb)
> Single stepping until exit from function call___do_global_ctors_aux,
> which has no line number information.
> 0x0fdd0c20 in gettimeofday () from /lib/libc.so.6
> (gdb)
> Single stepping until exit from function gettimeofday,
> which has no line number information.
> ArgusGetPackets (src=0x30070008) at ArgusSource.c:2022
> 2022 for (i = 0; i < src->ArgusInterfaces; i++) {
> (gdb)
> 2023 if (src->ArgusInterface[i].ArgusPd && (fd = pcap_fileno(src->ArgusInterface[i].ArgusPd) >= 0)) {
> (gdb)
> 307 src->ArgusInterfaceStatus = value;
> (gdb)
> 310 ArgusDebug (1, "setArgusInterfaceStatus(%d)\n", value);
> (gdb)
> 2022 for (i = 0; i < src->ArgusInterfaces; i++) {
> (gdb)
> 310 ArgusDebug (1, "setArgusInterfaceStatus(%d)\n", value);
> (gdb)
> argus[5858]: 10 Aug 09 11:13:40.771988 setArgusInterfaceStatus(0)
> 2022 for (i = 0; i < src->ArgusInterfaces; i++) {
> (gdb)
> 2042 if (!(src->ArgusReadingOffLine)) {
> (gdb)
> 2067 for (i = 0; i < src->ArgusInterfaces; i++) {
> (gdb)
> 2252 for (i = 0; i < src->ArgusInterfaces; i++) {
> (gdb)
> 2067 for (i = 0; i < src->ArgusInterfaces; i++) {
> (gdb)
> 2069 src->ArgusThisIndex = i;
> (gdb)
> 2070 if ((fd = fds[i]) != -1) {
> (gdb)
> 2067 for (i = 0; i < src->ArgusInterfaces; i++) {
> (gdb)
> 2093 if (pkts == 0) {
> (gdb)
> 2094 struct timespec tsbuf = {0, 25000000}, *ts = &tsbuf;
> (gdb)
> 2095 gettimeofday (&src->ArgusModel->ArgusGlobalTime, NULL);
> (gdb)
> 2094 struct timespec tsbuf = {0, 25000000}, *ts = &tsbuf;
> (gdb)
> 2095 gettimeofday (&src->ArgusModel->ArgusGlobalTime, NULL);
> (gdb)
> 2094 struct timespec tsbuf = {0, 25000000}, *ts = &tsbuf;
> (gdb)
> 2095 gettimeofday (&src->ArgusModel->ArgusGlobalTime, NULL);
> (gdb)
> 0x10050340 in call___do_global_ctors_aux ()
> (gdb)
> Single stepping until exit from function call___do_global_ctors_aux,
> which has no line number information.
> 0x0fdd0c20 in gettimeofday () from /lib/libc.so.6
> (gdb)
> Single stepping until exit from function gettimeofday,
> which has no line number information.
> ArgusGetPackets (src=0x30070008) at ArgusSource.c:2096
> 2096 nanosleep(ts, NULL);
> (gdb)
> 0x1004fd50 in call___do_global_ctors_aux ()
> (gdb)
> Single stepping until exit from function call___do_global_ctors_aux,
> which has no line number information.
> 0x30014890 in _dl_runtime_resolve () from /lib/ld.so.1
> (gdb)
> Single stepping until exit from function _dl_runtime_resolve,
> which has no line number information.
> 0x0fde0c7c in nanosleep () from /lib/libc.so.6
> (gdb)
> Single stepping until exit from function nanosleep,
> which has no line number information.
> 0x0fde0c88 in __nanosleep_nocancel () from /lib/libc.so.6
> (gdb)
> Single stepping until exit from function __nanosleep_nocancel,
> which has no line number information.
> ArgusGetPackets (src=0x30070008) at ArgusSource.c:2238
> 2238 if (!found)
> (gdb)
> 2259 setArgusFarReportInterval (ArgusModel, "0");
> (gdb)
> 2260 ArgusQueueManager(ArgusModel);
> (gdb)
> argus[5858]: 10 Aug 09 11:13:53.460484 ArgusProcessQueueTimeout(0x1012d008, 0x1012d3e8) done
> argus[5858]: 10 Aug 09 11:13:53.460593 ArgusQueueManager() turns 1 statusQueue 0 qs 0 items 0 cache 0 resort 0 reclaim 0 new 0 sends 0 bsends 0
> 2262 ArgusOutputProcess(ArgusOutputTask);
> (gdb)
> argus[5858]: 10 Aug 09 11:13:59.161973 ArgusOutputProcess(0x1012d9f0) starting
> argus[5858]: 10 Aug 09 11:13:59.162110 ArgusOutputStatusTime(0x1012d9f0) done
> 2266 gettimeofday (&src->ArgusEndTime, 0L);
> (gdb)
> 0x10050340 in call___do_global_ctors_aux ()
> (gdb)
> Single stepping until exit from function call___do_global_ctors_aux,
> which has no line number information.
> 0x0fdd0c20 in gettimeofday () from /lib/libc.so.6
> (gdb)
> Single stepping until exit from function gettimeofday,
> which has no line number information.
> ArgusGetPackets (src=0x30070008) at ArgusSource.c:2269
> 2269 ArgusDebug (4, "ArgusGetPackets () returning\n");
> (gdb)
> argus[5858]: 10 Aug 09 11:14:02.775186 ArgusGetPackets () returning
> 2271 }
> (gdb)
> main (argc=13, argv=0x7fab6aa4) at argus.c:558
> 558 ArgusDebug (1, "main() ArgusGetPackets returned: shuting down");
Peter Van Epp
More information about the argus
mailing list