BIND 10 trac1938, updated. 9a3d9604b0fd9dd3dcc5f00b06ebf08e4e4f68a5 [1938] corrected the use of 'wait for new' based on the revised semantics.
BIND 10 source code commits
bind10-changes at lists.isc.org
Fri Mar 22 07:10:44 UTC 2013
The branch, trac1938 has been updated
via 9a3d9604b0fd9dd3dcc5f00b06ebf08e4e4f68a5 (commit)
via 029681ebd000727c546f8d387df270e9c1415bd4 (commit)
from 506fdf871f529b20b295c8b3a18286c5f295a806 (commit)
Those revisions listed above that are new to this repository have
not appeared on any other notification email; so we list those
revisions in full, below.
- Log -----------------------------------------------------------------
commit 9a3d9604b0fd9dd3dcc5f00b06ebf08e4e4f68a5
Author: JINMEI Tatuya <jinmei at isc.org>
Date: Fri Mar 22 00:04:24 2013 -0700
[1938] corrected the use of 'wait for new' based on the revised semantics.
in some cases we can't simply use 'new' (but normally safe without it),
and in some cases we need additional synchronization points to make it
work more reliably.
commit 029681ebd000727c546f8d387df270e9c1415bd4
Author: JINMEI Tatuya <jinmei at isc.org>
Date: Fri Mar 22 00:01:37 2013 -0700
[1938] clarify and more rationalize the "only_new" ver of wait_for variants.
previously the semantics was a bit ambiguous and resulted in some
less predictable behavior. (and, non suprisingly, some usage cases
in features seem to be wrong about "wait for new").
-----------------------------------------------------------------------
Summary of changes:
tests/lettuce/features/queries.feature | 27 ++++++++
tests/lettuce/features/terrain/steps.py | 12 ++--
tests/lettuce/features/terrain/terrain.py | 69 +++++++++++++-------
tests/lettuce/features/xfrin_bind10.feature | 17 +++--
.../lettuce/features/xfrin_notify_handling.feature | 43 ++++++------
5 files changed, 115 insertions(+), 53 deletions(-)
-----------------------------------------------------------------------
diff --git a/tests/lettuce/features/queries.feature b/tests/lettuce/features/queries.feature
index b7105c6..b0a6fac 100644
--- a/tests/lettuce/features/queries.feature
+++ b/tests/lettuce/features/queries.feature
@@ -95,6 +95,10 @@ Feature: Querying feature
ns2.example.org. 3600 IN A 192.0.2.4
"""
+ # Make sure handling statistics command handling checked below is
+ # after this query
+ And wait for bind10 stderr message AUTH_SEND_NORMAL_RESPONSE
+
When I wait for new bind10 stderr message STATS_SEND_STATISTICS_REQUEST
# make sure Auth module receives a command
And wait for new bind10 stderr message AUTH_RECEIVED_COMMAND
@@ -137,6 +141,10 @@ Feature: Querying feature
ns2.example.org. 3600 IN A 192.0.2.4
"""
+ # Make sure handling statistics command handling checked below is
+ # after this query
+ And wait for new bind10 stderr message AUTH_SEND_NORMAL_RESPONSE
+
When I wait for new bind10 stderr message STATS_SEND_STATISTICS_REQUEST
# make sure Auth module receives a command
And wait for new bind10 stderr message AUTH_RECEIVED_COMMAND
@@ -167,6 +175,10 @@ Feature: Querying feature
example.org. 3600 IN SOA ns1.example.org. admin.example.org. 1234 3600 1800 2419200 7200
"""
+ # Make sure handling statistics command handling checked below is
+ # after this query
+ And wait for new bind10 stderr message AUTH_SEND_NORMAL_RESPONSE
+
When I wait for new bind10 stderr message STATS_SEND_STATISTICS_REQUEST
# make sure Auth module receives a command
And wait for new bind10 stderr message AUTH_RECEIVED_COMMAND
@@ -231,6 +243,10 @@ Feature: Querying feature
mail.example.org. 3600 IN A 192.0.2.10
"""
+ # Make sure handling statistics command handling checked below is
+ # after this query
+ And wait for bind10 stderr message AUTH_SEND_NORMAL_RESPONSE
+
When I wait for new bind10 stderr message STATS_SEND_STATISTICS_REQUEST
# make sure Auth module receives a command
And wait for new bind10 stderr message AUTH_RECEIVED_COMMAND
@@ -282,6 +298,10 @@ Feature: Querying feature
ns.sub.example.org. 3600 IN A 192.0.2.101
"""
+ # Make sure handling statistics command handling checked below is
+ # after this query
+ And wait for bind10 stderr message AUTH_SEND_NORMAL_RESPONSE
+
When I wait for new bind10 stderr message STATS_SEND_STATISTICS_REQUEST
# make sure Auth module receives a command
And wait for new bind10 stderr message AUTH_RECEIVED_COMMAND
@@ -333,6 +353,10 @@ Feature: Querying feature
A query for example.org type SSHFP should have rcode NOERROR
The last query response should have ancount 0
+ # Make sure handling statistics command handling checked below is
+ # after this query
+ And wait for bind10 stderr message AUTH_SEND_NORMAL_RESPONSE
+
When I wait for new bind10 stderr message STATS_SEND_STATISTICS_REQUEST
# make sure Auth module receives a command
And wait for new bind10 stderr message AUTH_RECEIVED_COMMAND
@@ -358,6 +382,9 @@ Feature: Querying feature
"""
shell.example.org. 3600 IN SSHFP 2 1 123456789abcdef67890123456789abcdef67890
"""
+ # Make sure handling statistics command handling checked below is
+ # after this query
+ And wait for bind10 stderr message AUTH_SEND_NORMAL_RESPONSE
When I wait for new bind10 stderr message STATS_SEND_STATISTICS_REQUEST
# make sure Auth module receives a command
diff --git a/tests/lettuce/features/terrain/steps.py b/tests/lettuce/features/terrain/steps.py
index e470acf..e41bb6d 100644
--- a/tests/lettuce/features/terrain/steps.py
+++ b/tests/lettuce/features/terrain/steps.py
@@ -37,8 +37,10 @@ def wait_for_stderr_message(step, times, new, process_name, message, not_message
output.
Parameter:
times: Check for the string this many times.
- new: (' new', optional): Only check the output printed since last time
- this step was used for this process.
+ new: (' new', optional): Only check the output from the process that has
+ not been covered in previous calls to this
+ function. See RunningProcess._wait_for_output_str
+ for details.
process_name ('<name> stderr'): Name of the process to check the output of.
message ('message <message>'): Output (part) to wait for.
not_message ('not <message>'): Output (part) to wait for, and fail
@@ -60,8 +62,10 @@ def wait_for_stdout_message(step, times, new, process_name, message, not_message
output.
Parameter:
times: Check for the string this many times.
- new: (' new', optional): Only check the output printed since last time
- this step was used for this process.
+ new: (' new', optional): Only check the output from the process that has
+ not been covered in previous calls to this
+ function. See RunningProcess._wait_for_output_str
+ for details.
process_name ('<name> stderr'): Name of the process to check the output of.
message ('message <message>'): Output (part) to wait for, and succeed.
not_message ('not <message>'): Output (part) to wait for, and fail
diff --git a/tests/lettuce/features/terrain/terrain.py b/tests/lettuce/features/terrain/terrain.py
index cc97a19..67ca802 100644
--- a/tests/lettuce/features/terrain/terrain.py
+++ b/tests/lettuce/features/terrain/terrain.py
@@ -114,6 +114,10 @@ class RunningProcess:
self._create_filenames()
self._start_process(args)
+ # used in _wait_for_output_str, map from (filename, (strings))
+ # to a file offset.
+ self.__file_offsets = {}
+
def _start_process(self, args):
"""
Start the process.
@@ -194,11 +198,29 @@ class RunningProcess:
os.remove(self.stderr_filename)
os.remove(self.stdout_filename)
- def _wait_for_output_str(self, filename, running_file, strings, only_new, matches = 1):
- """
- Wait for a line of output in this process. This will (if only_new is
- False) first check all previous output from the process, and if not
- found, check all output since the last time this method was called.
+ def _wait_for_output_str(self, filename, running_file, strings, only_new,
+ matches=1):
+ """
+ Wait for a line of output in this process. This will (if
+ only_new is False) check all output from the process including
+ that may have been checked before. If only_new is True, it
+ only checks output that has not been covered in previous calls
+ to this method for the file (if there was no such previous call to
+ this method, it works same as the case of only_new=False).
+
+ Care should be taken if only_new is to be set to True, as it may cause
+ counter-intuitive results. For example, assume the file is expected
+ to contain a line that has XXX and another line has YYY, but the
+ ordering is not predictable. If this method is called with XXX as
+ the search string, but the line containing YYY appears before the
+ target line, this method remembers the point in the file beyond
+ the line that has XXX. If a next call to this method specifies
+ YYY as the search string with only_new being True, the search will
+ fail. If the same string is expected to appear multiple times
+ and you want to catch the latest one, a more reliable way is to
+ specify the match number and set only_new to False, if the number
+ of matches is predictable.
+
For each line in the output, the given strings array is checked. If
any output lines checked contains one of the strings in the strings
array, that string (not the line!) is returned.
@@ -206,33 +228,34 @@ class RunningProcess:
filename: The filename to read previous output from, if applicable.
running_file: The open file to read new output from.
strings: Array of strings to look for.
- only_new: If true, only check output since last time this method was
- called. If false, first check earlier output.
+ only_new: See above.
matches: Check for the string this many times.
Returns a tuple containing the matched string, and the complete line
it was found in.
Fails if none of the strings was read after 10 seconds
(OUTPUT_WAIT_INTERVAL * OUTPUT_WAIT_MAX_INTERVALS).
"""
+ # Identify the start offset of search. if only_new=True, start from
+ # the farthest point we've reached in the file; otherwise start from
+ # the beginning.
+ if not filename in self.__file_offsets:
+ self.__file_offsets[filename] = 0
+ offset = self.__file_offsets[filename] if only_new else 0
+ running_file.seek(offset)
+
match_count = 0
- if not only_new:
- full_file = open(filename, "r")
- for line in full_file:
- for string in strings:
- if line.find(string) != -1:
- match_count += 1
- if match_count >= matches:
- full_file.close()
- return (string, line)
wait_count = 0
while wait_count < OUTPUT_WAIT_MAX_INTERVALS:
- where = running_file.tell()
line = running_file.readline()
+ where = running_file.tell()
if line:
for string in strings:
if line.find(string) != -1:
match_count += 1
if match_count >= matches:
+ # If we've gone further, update the recorded offset
+ if where > self.__file_offsets[filename]:
+ self.__file_offsets[filename] = where
return (string, line)
else:
wait_count += 1
@@ -245,8 +268,7 @@ class RunningProcess:
Wait for one of the given strings in this process's stderr output.
Parameters:
strings: Array of strings to look for.
- only_new: If true, only check output since last time this method was
- called. If false, first check earlier output.
+ only_new: See _wait_for_output_str.
matches: Check for the string this many times.
Returns a tuple containing the matched string, and the complete line
it was found in.
@@ -261,8 +283,7 @@ class RunningProcess:
Wait for one of the given strings in this process's stdout output.
Parameters:
strings: Array of strings to look for.
- only_new: If true, only check output since last time this method was
- called. If false, first check earlier output.
+ only_new: See _wait_for_output_str.
matches: Check for the string this many times.
Returns a tuple containing the matched string, and the complete line
it was found in.
@@ -342,8 +363,7 @@ class RunningProcesses:
Parameters:
process_name: The name of the process to check the stderr output of.
strings: Array of strings to look for.
- only_new: If true, only check output since last time this method was
- called. If false, first check earlier output.
+ only_new: See _wait_for_output_str.
matches: Check for the string this many times.
Returns the matched string.
Fails if none of the strings was read after 10 seconds
@@ -362,8 +382,7 @@ class RunningProcesses:
Parameters:
process_name: The name of the process to check the stdout output of.
strings: Array of strings to look for.
- only_new: If true, only check output since last time this method was
- called. If false, first check earlier output.
+ only_new: See _wait_for_output_str.
matches: Check for the string this many times.
Returns the matched string.
Fails if none of the strings was read after 10 seconds
diff --git a/tests/lettuce/features/xfrin_bind10.feature b/tests/lettuce/features/xfrin_bind10.feature
index f67f701..90a1144 100644
--- a/tests/lettuce/features/xfrin_bind10.feature
+++ b/tests/lettuce/features/xfrin_bind10.feature
@@ -33,7 +33,10 @@ Feature: Xfrin
And wait for new bind10 stderr message XFRIN_ZONE_WARN
# But after complaining, the zone data should be accepted.
Then wait for new bind10 stderr message XFRIN_TRANSFER_SUCCESS not XFRIN_XFR_PROCESS_FAILURE
- Then wait for new bind10 stderr message ZONEMGR_RECEIVE_XFRIN_SUCCESS
+ # there's no guarantee this is logged before XFRIN_TRANSFER_SUCCESS, so
+ # we can't reliably use 'wait for new'. In this case this should be the
+ # only occurrence of this message, so this should be okay.
+ Then wait for bind10 stderr message ZONEMGR_RECEIVE_XFRIN_SUCCESS
A query for www.example.org to [::1]:47806 should have rcode NOERROR
# The transferred zone should have 11 non-NSEC3 RRs and 1 NSEC3 RR.
@@ -56,7 +59,8 @@ Feature: Xfrin
Then I send bind10 the command Xfrin retransfer example.org IN ::1 47807
And wait for new bind10 stderr message XFRIN_ZONE_INVALID
And wait for new bind10 stderr message XFRIN_INVALID_ZONE_DATA
- Then wait for new bind10 stderr message ZONEMGR_RECEIVE_XFRIN_FAILED
+ # We can't use 'wait for new' here; see above.
+ Then wait for bind10 stderr message ZONEMGR_RECEIVE_XFRIN_FAILED
A query for example.org type NS to [::1]:47806 should have rcode NOERROR
And transfer result should have 13 rrs
@@ -82,7 +86,8 @@ Feature: Xfrin
# Make sure it is fully open
When I send bind10 the command Xfrin retransfer example.org
Then wait for new bind10 stderr message XFRIN_TRANSFER_SUCCESS not XFRIN_XFR_PROCESS_FAILURE
- And wait for new bind10 stderr message ZONEMGR_RECEIVE_XFRIN_SUCCESS
+ # this can't be 'wait for new'; see above.
+ And wait for bind10 stderr message ZONEMGR_RECEIVE_XFRIN_SUCCESS
# First to master, a transfer should then fail
When I send bind10 the following commands with cmdctl port 47804:
@@ -139,7 +144,8 @@ Feature: Xfrin
# zone is invalid and then reject it.
And wait for new bind10 stderr message XFRIN_ZONE_INVALID
And wait for new bind10 stderr message XFRIN_INVALID_ZONE_DATA
- Then wait for new bind10 stderr message ZONEMGR_RECEIVE_XFRIN_FAILED
+ # This can't be 'wait for new'
+ Then wait for bind10 stderr message ZONEMGR_RECEIVE_XFRIN_FAILED
# The zone still doesn't exist as it is rejected.
# FIXME: This step fails. Probably an empty zone is created in the data
# source :-|. This should be REFUSED, not SERVFAIL.
@@ -179,7 +185,8 @@ Feature: Xfrin
When I send bind10 the command Xfrin retransfer example. IN ::1 47807
Then wait for new bind10 stderr message XFRIN_GOT_INCREMENTAL_RESP
Then wait for new bind10 stderr message XFRIN_IXFR_TRANSFER_SUCCESS not XFRIN_XFR_PROCESS_FAILURE
- Then wait for new bind10 stderr message ZONEMGR_RECEIVE_XFRIN_SUCCESS
+ # This can't be 'wait for new'
+ Then wait for bind10 stderr message ZONEMGR_RECEIVE_XFRIN_SUCCESS
A query for example. type SOA to [::1]:47806 should have rcode NOERROR
The answer section of the last query response should be
diff --git a/tests/lettuce/features/xfrin_notify_handling.feature b/tests/lettuce/features/xfrin_notify_handling.feature
index be0f7e0..9eee067 100644
--- a/tests/lettuce/features/xfrin_notify_handling.feature
+++ b/tests/lettuce/features/xfrin_notify_handling.feature
@@ -51,14 +51,19 @@ Feature: Xfrin incoming notify handling
When I send bind10 with cmdctl port 47804 the command Xfrout notify example.org IN
Then wait for new master stderr message XFROUT_NOTIFY_COMMAND
Then wait for new bind10 stderr message AUTH_RECEIVED_NOTIFY
- Then wait for new bind10 stderr message ZONEMGR_RECEIVE_NOTIFY
- Then wait for new bind10 stderr message XFRIN_XFR_TRANSFER_STARTED
- Then wait for new bind10 stderr message XFRIN_TRANSFER_SUCCESS not XFRIN_XFR_PROCESS_FAILURE
- Then wait for new bind10 stderr message ZONEMGR_RECEIVE_XFRIN_SUCCESS
- Then wait 5 times for new master stderr message NOTIFY_OUT_SENDING_NOTIFY
- Then wait for new master stderr message NOTIFY_OUT_RETRY_EXCEEDED
+ # From this point we can't reliably 'wait for new' because the ordering
+ # of logs from different processes is unpredictable. But these
+ # should be okay in this case.
+ Then wait for bind10 stderr message ZONEMGR_RECEIVE_NOTIFY
+ Then wait for bind10 stderr message XFRIN_XFR_TRANSFER_STARTED
+ Then wait for bind10 stderr message XFRIN_TRANSFER_SUCCESS not XFRIN_XFR_PROCESS_FAILURE
+ Then wait for bind10 stderr message ZONEMGR_RECEIVE_XFRIN_SUCCESS
+ Then wait for master stderr message NOTIFY_OUT_REPLY_RECEIVED
A query for www.example.org to [::1]:47806 should have rcode NOERROR
+ # Make sure handling statistics command handling checked below is
+ # after this query
+ And wait for bind10 stderr message AUTH_SEND_NORMAL_RESPONSE
#
# Test for statistics
@@ -67,7 +72,9 @@ Feature: Xfrin incoming notify handling
#
# wait until the last stats requesting is finished
- wait for new master stderr message STATS_SEND_STATISTICS_REQUEST
+ # note that this does not 100% guarantee the stats updated Xfrout
+ # statistics. But there doesn't seem to be a better log message that
+ # suggests this event.
wait for new master stderr message XFROUT_RECEIVED_GETSTATS_COMMAND
When I query statistics zones of bind10 module Xfrout with cmdctl port 47804
@@ -155,12 +162,12 @@ Feature: Xfrin incoming notify handling
When I send bind10 with cmdctl port 47804 the command Xfrout notify example.org IN
Then wait for new master stderr message XFROUT_NOTIFY_COMMAND
Then wait for new bind10 stderr message AUTH_RECEIVED_NOTIFY
- Then wait for new bind10 stderr message ZONEMGR_RECEIVE_NOTIFY
- Then wait for new bind10 stderr message XFRIN_XFR_TRANSFER_STARTED
- Then wait for new bind10 stderr message XFRIN_XFR_TRANSFER_PROTOCOL_VIOLATION not XFRIN_XFR_TRANSFER_STARTED
- Then wait for new bind10 stderr message ZONEMGR_RECEIVE_XFRIN_FAILED not ZONEMGR_RECEIVE_XFRIN_SUCCESS
- Then wait 5 times for new master stderr message NOTIFY_OUT_SENDING_NOTIFY
- Then wait for new master stderr message NOTIFY_OUT_RETRY_EXCEEDED
+ # can't use 'wait for new' below.
+ Then wait for bind10 stderr message ZONEMGR_RECEIVE_NOTIFY
+ Then wait for bind10 stderr message XFRIN_XFR_TRANSFER_STARTED
+ Then wait for bind10 stderr message XFRIN_XFR_TRANSFER_PROTOCOL_VIOLATION not XFRIN_XFR_TRANSFER_STARTED
+ Then wait for bind10 stderr message ZONEMGR_RECEIVE_XFRIN_FAILED not ZONEMGR_RECEIVE_XFRIN_SUCCESS
+ Then wait for master stderr message NOTIFY_OUT_REPLY_RECEIVED
A query for www.example.org to [::1]:47806 should have rcode NXDOMAIN
@@ -170,8 +177,7 @@ Feature: Xfrin incoming notify handling
# check for statistics change
#
- # wait until the last stats requesting is finished
- wait for new master stderr message STATS_SEND_STATISTICS_REQUEST
+ # wait until stats request at least after NOTIFY_OUT_REPLY_RECEIVED
wait for new master stderr message XFROUT_RECEIVED_GETSTATS_COMMAND
When I query statistics zones of bind10 module Xfrout with cmdctl port 47804
@@ -220,8 +226,7 @@ Feature: Xfrin incoming notify handling
# check statistics change
#
- # wait until the last stats requesting is finished
- wait for new master stderr message STATS_SEND_STATISTICS_REQUEST
+ # wait until stats request at least after NOTIFY_OUT_TIMEOUT
wait for new master stderr message XFROUT_RECEIVED_GETSTATS_COMMAND
When I query statistics zones of bind10 module Xfrout with cmdctl port 47804
@@ -277,7 +282,7 @@ Feature: Xfrin incoming notify handling
Xfrout shutdown
"""
last bindctl output should not contain "error"
- And wait 2 times for master stderr message XFROUT_STARTED
+ And wait for new master stderr message XFROUT_STARTED
A query for www.example.com to [::1]:47806 should have rcode REFUSED
@@ -317,7 +322,7 @@ Feature: Xfrin incoming notify handling
Zonemgr shutdown
"""
last bindctl output should not contain "error"
- And wait 2 times for bind10 stderr message ZONEMGR_STARTED
+ And wait for new bind10 stderr message ZONEMGR_STARTED
A query for www.example.org to [::1]:47806 should have rcode NXDOMAIN
More information about the bind10-changes
mailing list