Index: [Article Count Order] [Thread]

Date: Wed, 11 Jul 2007 17:09:53 +0900
From: Mitsuru Chinen <mitch@linux.vnet.ibm.com>
Subject: [dhcptest:00190] Timeout issue in Maximum Retransmission Time tests
To: dhcptest@tahi.org
Message-Id: <20070711170953.570615a5.mitch@linux.vnet.ibm.com>
X-Mail-Count: 00190

Dear TAHI Project folks,

At the following tests, when waiting for retransmission in RT,
wait_for_{solicit,request,confirm,renew,rebind} *sometimes* ends
earlier than expected.

 #32 Part D : Maximum Retransmission Time of solicit message
 #37 Part D : Maximum Retransmission Time of solicit message
 #41 Part C : Maximum Retransmission Time of Confirm message
 #46 Part C : Maximum Retransmission Time of Renew message, T1 and T2 non-zero
 #47 Part D : Maximum Retransmission Duration of Renew message, T1 and T2 non-zero

My environment of TN is:
 OS: FreeBSD 6.2-RELEASE
 perl: v5.8.8
 TestVersion: DHCPv6_Self_Test_02
 ToolVersion: REL_3_0_12

For example, I got Fail at the first confirm message transmission in #41.
But according to the packet dump:

  # tcpdump -n -r 41.html.Link0.dump | grep confirm
  reading from file 41.html.Link0.dump, link-type EN10MB (Ethernet)
  16:26:47.727945 IP6 fe80::20e:cff:fe35:f950.547 > ff02::1:2.547: dhcp6 confirm
  16:26:48.764826 IP6 fe80::20e:cff:fe35:f950.547 > ff02::1:2.547: dhcp6 confirm

A confirm message is retransmitted after 1.036881[sec].
As the range of RT is from 0.9 to 1.1[sec] at the first transmission,
the retransmission is occurred in the acceptable range.

I created a proposal patch for this. However, the one which should
be fixed may be the v6eval rather than the testsuite.
But anyway, could you look at this issue?

Best Regards,
----
Mitsuru Chinen <mitch@linux.vnet.ibm.com>


diff -upr DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_17_1_2_SolRetransMRT.seq DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_17_1_2_SolRetransMRT.seq
--- DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_17_1_2_SolRetransMRT.seq	2007-02-02 16:49:45.000000000 +0900
+++ DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_17_1_2_SolRetransMRT.seq	2007-07-06 13:40:12.000000000 +0900
@@ -100,7 +100,7 @@ while(check_equal($interval,$SOL_MAX_RT,
 	}else{
 		$timeout = (1 + $RAND) * $IRT;
 	}
-	($retsol2,%sol2) = wait_for_solicit($IF0, $timeout);
+	($retsol2,%sol2) = wait_for_solicit($IF0, $timeout + 1);
 	$nextime = getElapsedtime(\%sol2);
 	if($retsol2 != 0){
 		dhcpExitFail;
@@ -108,6 +108,10 @@ while(check_equal($interval,$SOL_MAX_RT,
 
 	$interval = $nextime - $pretime;
 	vLogHTML("<FONT COLOR=\"#FF0000\">RT = $interval <FONT><BR>");	
+	if ($interval gt $timeout) {
+		vLogHTML("<FONT COLOR=\"#FF0000\">Actual RT is bigger than the expected maximum value<FONT><BR>");
+		dhcpExitFail;
+	}
 	$pretime = $nextime;
 }
 ($retsol2,%sol2) = wait_for_solicit($IF0, $timeout);
diff -upr DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_1_ReqRetransMRT.seq DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_1_ReqRetransMRT.seq
--- DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_1_ReqRetransMRT.seq	2007-02-07 14:07:38.000000000 +0900
+++ DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_1_ReqRetransMRT.seq	2007-07-06 13:50:04.000000000 +0900
@@ -117,13 +117,17 @@ while(check_equal($interval,$REQ_MAX_RT,
 	}else{
 		$timeout = (1 + $RAND) * $IRT;
 	}
-	($retreq2,%req2) = wait_for_request($IF0, $timeout);
+	($retreq2,%req2) = wait_for_request($IF0, $timeout + 1);
 	if($retreq2 != 0){
 		dhcpExitFail;
 	}
 	$nextime = getElapsedtime(\%req2);
 	$interval = $nextime - $pretime;	
 	vLogHTML("<FONT COLOR=\"#FF0000\">RT = $interval  <FONT><BR>");
+	if ($interval gt $timeout) {
+		vLogHTML("<FONT COLOR=\"#FF0000\">Actual RT is bigger than the expected maximum value<FONT><BR>");
+		dhcpExitFail;
+	}
 	$pretime = $nextime;
 	$rc++;
 	if(($rc > $MRC)){
diff -upr DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_2_CnfRetransMRT.seq DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_2_CnfRetransMRT.seq
--- DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_2_CnfRetransMRT.seq	2007-02-07 14:07:39.000000000 +0900
+++ DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_2_CnfRetransMRT.seq	2007-07-06 13:37:35.000000000 +0900
@@ -165,7 +165,7 @@ while(check_equal($interval,$CNF_MAX_RT,
 	}else{
 		$timeout = (1 + $RAND) * $IRT;
 	}
-	($retcnf2,%cnf2) = wait_for_confirm($IF0, $timeout);
+	($retcnf2,%cnf2) = wait_for_confirm($IF0, $timeout + 1);
 	if($retcnf2 != 0){
 #		vRemoteAsyncWait();
 		dhcpExitFail;
@@ -174,6 +174,11 @@ while(check_equal($interval,$CNF_MAX_RT,
 	$rd = $nextime - $start;
 	vClear($IF0);
 	$interval = $nextime - $pretime;	
+	vLogHTML("<FONT COLOR=\"#FF0000\">RT = $interval  <FONT><BR>");
+	if ($interval gt $timeout) {
+		vLogHTML("<FONT COLOR=\"#FF0000\">Actual RT is bigger than the expected maximum value<FONT><BR>");
+		dhcpExitFail;
+	}
 	$pretime = $nextime;
 	print "\n rd = $rd \n";
 	if($rd >= $MRD){
diff -upr DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_3_RenRetransMRT.seq DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_3_RenRetransMRT.seq
--- DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_3_RenRetransMRT.seq	2007-02-07 14:07:39.000000000 +0900
+++ DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_3_RenRetransMRT.seq	2007-07-06 13:42:17.000000000 +0900
@@ -152,7 +152,7 @@ while(check_equal($interval,$REN_MAX_RT,
 	}else{
 		$timeout = (1 + $RAND) * $IRT;
 	}
-	($retren2,%ren2) = wait_for_renew($IF0, $timeout);
+	($retren2,%ren2) = wait_for_renew($IF0, $timeout + 1);
 	if($retren2 != 0){
 		dhcpExitFail;
 	}
@@ -160,6 +160,10 @@ while(check_equal($interval,$REN_MAX_RT,
 	$rd = $nextime - $start;
 	$interval = $nextime - $pretime;	
 	vLogHTML("<FONT COLOR=\"#FF0000\">RT = $interval </FONT><BR>");
+	if ($interval gt $timeout) {
+		vLogHTML("<FONT COLOR=\"#FF0000\">Actual RT is bigger than the expected maximum value<FONT><BR>");
+		dhcpExitFail;
+	}
 	$pretime = $nextime;
 	if($rd >=  $MRD){
 		vLogHTML('<FONT COLOR="#FF0000">Cannot reach REN_MAX_RT </FONT><BR>');
diff -upr DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_3_RetransRen.seq DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_3_RetransRen.seq
--- DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_3_RetransRen.seq	2007-02-07 14:07:39.000000000 +0900
+++ DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_3_RetransRen.seq	2007-07-06 13:46:11.000000000 +0900
@@ -154,7 +154,7 @@ do {
 	}else{
 		$timeout = (1 + $RAND) * $IRT;
 	}
-	($retren2,%ren2) = wait_for_renew($IF0, $timeout);
+	($retren2,%ren2) = wait_for_renew($IF0, $timeout + 1);
 	if($retren2 != 0){
 		dhcpExitFail;
 	}
@@ -162,6 +162,11 @@ do {
 	$rd = $nextime - $start;
 	$interval = $nextime - $pretime;
 	vLogHTML("<FONT COLOR=\"#FF0000\">RD = $rd</FONT><BR>");
+	vLogHTML("<FONT COLOR=\"#FF0000\">RT = $interval  <FONT><BR>");
+	if ($interval gt $timeout) {
+		vLogHTML("<FONT COLOR=\"#FF0000\">Actual RT is bigger than the expected maximum value<FONT><BR>");
+		dhcpExitFail;
+	}
 	$pretime = $nextime;
 }while($rd+$timeout < $MRD);
 #--------------------------------------------------------------#
diff -upr DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_4_RebRetransMRT.seq DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_4_RebRetransMRT.seq
--- DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_4_RebRetransMRT.seq	2007-02-07 14:07:39.000000000 +0900
+++ DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_4_RebRetransMRT.seq	2007-07-06 13:48:20.000000000 +0900
@@ -156,7 +156,7 @@ while(check_equal($interval,$REB_MAX_RT,
 	}else{
 		$timeout = (1 + $RAND) * $IRT;
 	}
-	($retreb2,%reb2) = wait_for_rebind($IF0, $timeout);
+	($retreb2,%reb2) = wait_for_rebind($IF0, $timeout + 1);
 	if($retreb2 != 0){
 		dhcpExitFail;
 	}
@@ -166,6 +166,10 @@ while(check_equal($interval,$REB_MAX_RT,
 	$pretime = $nextime;
 	vClear($IF0);
 	vLogHTML("<FONT COLOR=\"#FF0000 \"> RT = $interval </FONT><BR>");
+	if ($interval gt $timeout) {
+		vLogHTML("<FONT COLOR=\"#FF0000\">Actual RT is bigger than the expected maximum value<FONT><BR>");
+		dhcpExitFail;
+	}
 	if($rd >= $MRD){
 		vLogHTML('<FONT COLOR="#FF0000">Cannot reach REB_MAX_RT </FONT><BR>');
 		dhcpExitFail;