Index: [Article Count Order] [Thread]

Date: Wed, 11 Jul 2007 17:56:07 +0900
From: <Hideshi.Enokihara@jp.yokogawa.com>
Subject: [dhcptest:00191] Re: Timeout issue in Maximum Retransmission Time tests
To: <mitch@linux.vnet.ibm.com>
Cc: <dhcptest@tahi.org>
Message-Id: <0260031F55435342859BFB2CCA6773D81B898BC5@EXCHANGE03.jp.ykgw.net>
In-Reply-To: <20070711170953.570615a5.mitch@linux.vnet.ibm.com>
X-Mail-Count: 00191

Hello  Chinen-san,

Thank you so much for your report.
We will fix these issues as soon as possible usig your patches as
tentative solution.

Thanks again.

Best regards,

> -----Original Message-----
> From: Mitsuru Chinen [mailto:mitch@linux.vnet.ibm.com] 
> Sent: Wednesday, July 11, 2007 5:10 PM
> To: dhcptest@tahi.org
> Subject: [dhcptest:00190] Timeout issue in Maximum 
> Retransmission Time tests
> 
> 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_SolRet
> ransMRT.seq 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_17_1_2_SolRetr
> ansMRT.seq
> --- 
> DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_17_1_2_SolRet
> ransMRT.seq	2007-02-02 16:49:45.000000000 +0900
> +++ 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_17_1_2_SolRetr
> ansMRT.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_ReqRet
> ransMRT.seq 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_1_ReqRetr
> ansMRT.seq
> --- 
> DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_1_ReqRet
> ransMRT.seq	2007-02-07 14:07:38.000000000 +0900
> +++ 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_1_ReqRetr
> ansMRT.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_CnfRet
> ransMRT.seq 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_2_CnfRetr
> ansMRT.seq
> --- 
> DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_2_CnfRet
> ransMRT.seq	2007-02-07 14:07:39.000000000 +0900
> +++ 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_2_CnfRetr
> ansMRT.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_RenRet
> ransMRT.seq 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_3_RenRetr
> ansMRT.seq
> --- 
> DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_3_RenRet
> ransMRT.seq	2007-02-07 14:07:39.000000000 +0900
> +++ 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_3_RenRetr
> ansMRT.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_Retran
> sRen.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_Retran
> sRen.seq	2007-02-07 14:07:39.000000000 +0900
> +++ 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_3_Retrans
> Ren.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_RebRet
> ransMRT.seq 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_4_RebRetr
> ansMRT.seq
> --- 
> DHCPv6_Self_Test_P2_1_0_2.orig/rfc3315/C_RFC3315_18_1_4_RebRet
> ransMRT.seq	2007-02-07 14:07:39.000000000 +0900
> +++ 
> DHCPv6_Self_Test_P2_1_0_2.new/rfc3315/C_RFC3315_18_1_4_RebRetr
> ansMRT.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;
> 
>