Subject: Routing loop?

From: [email-masked] (Bruce A. Mah)
Date: Fri, 01 Nov 1996 14:33:00 -0800

There appears to be a routing loop somewhere in the MBONE.  At first I thought 
they were just large bursts of packets from certain hosts sending to the Mbone 
RTP Audio session, but these bursts are composed of packets with identical IP 
id fields and sometimes decreasing TTLs.

Unfortunately I don't have the means (or the ability) to trace this 
down...thought someone would be interested though.  :-)

A snapshot of forty packets (from tcpdump -v) follows...you can see a lot more 
by letting this run for a few minutes.

Bruce.

-----

14:24:21.216406 cirrus.stl.nps.navy.mil.3915 > 224.2.0.1.23457: udp 68 (ttl 
178, id 45213)
14:24:21.232998 cirrus.stl.nps.navy.mil.3915 > 224.2.0.1.23457: udp 68 (ttl 
178, id 45213)
14:24:21.233974 cirrus.stl.nps.navy.mil.3915 > 224.2.0.1.23457: udp 68 (ttl 
177, id 45213)
14:24:21.237878 cirrus.stl.nps.navy.mil.3915 > 224.2.0.1.23457: udp 68 (ttl 
177, id 45213)
14:24:21.308150 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 186, id 4154)
14:24:21.329622 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 182, id 4154)
14:24:21.332550 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 181, id 4154)
14:24:21.338406 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 181, id 4154)
14:24:21.339382 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 178, id 4154)
14:24:21.340358 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 179, id 4154)
14:24:21.345238 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 178, id 4154)
14:24:21.348166 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 176, id 4154)
14:24:21.350118 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 175, id 4154)
14:24:21.358902 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 175, id 4154)
14:24:21.358902 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 173, id 4154)
14:24:21.359878 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 172, id 4154)
14:24:21.369638 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 172, id 4154)
14:24:21.375494 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 170, id 4154)
14:24:21.375494 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 169, id 4154)
14:24:21.393062 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 169, id 4154)
14:24:21.395990 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 166, id 4154)
14:24:21.399894 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 167, id 4154)
14:24:21.413558 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 166, id 4154)
14:24:21.414534 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 164, id 4154)
14:24:21.414534 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 163, id 4154)
14:24:21.415510 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 163, id 4154)
14:24:21.415510 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 161, id 4154)
14:24:21.416486 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 160, id 4154)
14:24:21.432102 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 160, id 4154)
14:24:21.432102 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 158, id 4154)
14:24:21.432102 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 157, id 4154)
14:24:21.435030 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 157, id 4154)
14:24:21.437958 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 155, id 4154)
14:24:21.438934 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 154, id 4154)
14:24:21.442838 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 154, id 4154)
14:24:21.446742 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 152, id 4154)
14:24:21.447718 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 151, id 4154)
14:24:21.465286 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 151, id 4154)
14:24:21.479924 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 148, id 4154)
14:24:21.479924 140.173.8.3.32790 > 224.2.0.1.23457: udp 60 (ttl 149, id 4154)

---

From: John Hawkinson <[email-masked]>
Date: Sat, 2 Nov 1996 00:04:20 -0500 (EST)

> There appears to be a routing loop somewhere in the MBONE.  At first
> I thought they were just large bursts of packets from certain hosts
> sending to the Mbone RTP Audio session, but these bursts are
> composed of packets with identical IP id fields and sometimes
> decreasing TTLs.
> 

Have you tried mtrace? It is usually quite clear about the source of
the packet duplication (just look for negative numbers in the
statistics section). Shortly after you sent the mail I looked and did
not see these duplicates.

That implies the source of the duplicates is somewhere along the
path from you to dartsun3 that does not appear on my path.

I've attached my current path there...

--jhawk

[all-purpose-gunk!jhawk] ~> mtrace -s 140.173.8.3
Mtrace from 140.173.8.3 to 199.94.220.184 via group 224.2.0.1
...
 -2  cambridge1-mbone1.bbnplanet.net (199.94.207.2)  DVMRP  thresh^ 16  
 -3  * dec3800-2-fddi-0.WestOrange.mci.net (204.70.64.61)  DVMRP  thresh^ 32  
 -4  * dec3800-2-fddi-1.Denver.mci.net (204.70.152.77)  DVMRP  thresh^ 1  
 -5  * dec3800-2-fddi-1.SanFrancisco.mci.net (204.70.158.77)  DVMRP  thresh^ 1  
 -6  * mbone.nsi.nasa.gov (192.203.230.241)  DVMRP  thresh^ 64  
 -7  mbone2.nsi.nasa.gov (192.203.230.242)  DVMRP  thresh^ 1  
 -8  * ames.dart.net (192.52.195.128)  DVMRP  thresh^ 32  
 -9  * * sun.dart.net (140.173.192.1)  DVMRP  thresh^ 1  
-10  ? (140.173.8.3)

---

From: Bill Fenner <[email-masked]>
Date: Fri, 1 Nov 1996 22:56:10 PST

In message <[email-masked]> you write:
>There appears to be a routing loop somewhere in the MBONE.

I suspect it's closer to Berkeley.  I run a duplicate-watcher most of the
time, and virtually all of the duplicate packets today were either from
inside of Cisco, or were probably attributable to PIM Assert message
processing.  I certainly didn't see the loop-ish stuff from 140.173.8.3 .

  Bill

---

From: [email-masked] (Bruce A. Mah)
Date: Sat, 02 Nov 1996 10:06:38 -0800

> processing.  I certainly didn't see the loop-ish stuff from 140.173.8.3 .

Well "close to Berkeley" is still in the MBONE right?  :-)

Van suggests that it was due to a new tunnel added between UCB and LBNL for 
some DARTNET-related work, so that would make it *very* close.  The situation 
seems to be at least partially corrected, although I'm seeing a few duplicates 
this morning.

Sorry for the false alarm,

Bruce.

---

From: Bill Fenner <[email-masked]>
Date: Sat, 2 Nov 1996 10:26:55 PST

I use this perl script to watch for duplicates.  Cisco puts out hundreds
of duplicates a day, so I usually use

mdups -t not src net 171.68 and not src net 171.69

You can give "mdups -t" any tcpdump expression, or you can run tcpdump
yourself as in the comments at the top and then pipe the output thru mdups.
Once it gives some output, you can cut'n'paste the hostname and group into
an mtrace command line and let mtrace tell you where the duplicates are
happening.

This tends to tickle perl bugs so it sometimes dumps core.  Perhaps perl5
is more robust, I haven't tried it.

  Bill

#!/import/misc/bin/perl -s
# mdups - examine a 'tcpdump -v' trace and print more information
# about packets with duplicate ip id's
# based on Van Jacobson's mdups.sh
# - Bill Fenner, 8Nov94
#
# Recommended usage: tcpdump -e -l -v udp and ip multicast | mdups
# use "mdups -t" to make it run tcpdump for you
# sort +0 -1 +9 -10 groups hosts together.

$|=1;		# line-buffer stdout
$nuketime = 30;
$do_nuke = 0;
$spp = 2;

if ($t) {
	$args = "-e -l -v \\( udp and ip multicast and not broadcast \\)";
	if ($n) {
		$args = "-n " . $args;
	}
	if ($#ARGV >= $[) {
		$args .= " and \\( " . join(" ", @ARGV) . " \\)";
	}
print "tcpdump $args\n";
	#open(TCPDUMP, "tcpdump ${nflag} -e -l -v udp and ip multicast and not broadcast |") || die "tcpdump: $!\n";
	open(TCPDUMP, "tcpdump ${args} |") || die "tcpdump: $!\n";
} else {
	*TCPDUMP = *STDIN;
}

$SIG{'ALRM'} = "nuke_history";
alarm($nuketime);

while (<TCPDUMP>) {
	if ($do_nuke) {
		%last = ();
		$do_nuke = 0;
	}
#	print;
	chop;
	next if /frag/;
	s/\(DF\) //;
	s/\[tos [^]]+\]//;
#	($tm,$host,$ttl,$id) = (split)[0,1,7,9];
# without -e ^^^
	($tm,$e,$host,$dst,$ttl,$id) = (split)[0,1,5,7,11,13];
	$host =~ s/\.[^.]+$//;
	$dst =~ s/\.[^.]+$//;
	$ttl =~ s/,$//;
	$id =~ s/\)$//;
#	if ($id == 0) {
#		print ">>>$_\n";
#	}
	# Assume that id==0 is a malformed line
	if ($id == 0) {
		next;
	}
	($h,$m,$s) = split(/:/,$tm);
	$s += $m * 60 + $h * 3600;
	$count = 0;
	if ($i = $last{$host . "/" . $id}) {
		($os,$oe,$ottl,$count) = split("/",$i);
		$count++;
		if ($s - $os > $count * $spp) {	# If the rate is < 1 packet
						# per $spp seconds, assume
						# that it is sequence-wrap
						# and not a duplicate.
			$count = 0;
		} else {
		print $tm," ";
		print $host;
		print "/$e" if ($v);
		printf(" %s oTTL %d delta %d deltatime %d ms id %d ndups %d\n",
			$dst,$ottl,$ottl - $ttl,($s - $os) * 1000,$id,$count);
		if ($e ne $oe) {
			print ">>> oe $oe e $e\n";
		}
		$s=$os; $ttl=$ottl;	# all deltas from original packet
		}
	}
	$last{$host . "/" . $id} = join("/",$s,$e,$ttl,$count);
}

sub nuke_history {
	$do_nuke = 1;

	alarm($nuketime);
	return;
}