[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.

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

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

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