BIT-1941: improve reliability of broker.disconnect unit test

CHANGES

@@ -1,4 +1,8 @@
 
+2.5-721 | 2018-07-02 16:29:21 -0500
+
+  * BIT-1941: improve reliability of broker.disconnect unit test (Corelight)
+
 2.5-719 | 2018-06-27 20:02:52 -0500
 
   * Fix some typos and formatting in NEWS and other documentation

VERSION

@@ -1 +1 @@
-2.5-719
+2.5-721

testing/btest/Baseline/broker.disconnect/recv.broker.filtered.log

@@ -1 +0,0 @@
-1502645128.235998 Broker::STATUS peer-added 127.0.0.1 XXX handshake successful

testing/btest/Baseline/broker.disconnect/recv.recv.out

@@ -1,2 +1,2 @@
 peer added, handshake successful
-Something receiver, 1
+receiver got event, 1

testing/btest/Baseline/broker.disconnect/recv2.broker.filtered.log

@@ -1 +0,0 @@
-1502645286.464675 Broker::STATUS peer-added 127.0.0.1 XXX handshake successful

testing/btest/Baseline/broker.disconnect/recv2.recv2.out

@@ -1,2 +1,2 @@
 peer added, handshake successful
-Something receiver, 2
+receiver got event, 2

testing/btest/Baseline/broker.disconnect/send.broker.filtered.log

@@ -1,4 +0,0 @@
-1524513026.795171 Broker::STATUS peer-added 127.0.0.1 XXX received handshake from remote core
-1524513033.340316 Broker::STATUS connection-terminated 127.0.0.1 XXX lost remote peer
-1524513035.437373 Broker::STATUS peer-added 127.0.0.1 XXX received handshake from remote core
-1524513041.743002 Broker::STATUS connection-terminated 127.0.0.1 XXX lost remote peer

testing/btest/Baseline/broker.disconnect/send.send.out

@@ -1,6 +1,4 @@
 peer added, received handshake from remote core
-Something sender, 1
 peer lost, lost remote peer
 peer added, received handshake from remote core
-Something sender, 2
 peer lost, lost remote peer

testing/btest/broker/disconnect.bro

@@ -1,22 +1,19 @@
 # @TEST-SERIALIZE: comm
-#
+
 # @TEST-EXEC: btest-bg-run recv "bro -B broker -b ../recv.bro >recv.out"
 # @TEST-EXEC: btest-bg-run send "bro -B broker -b ../send.bro >send.out"
-#
+
-# @TEST-EXEC: sleep 6 && kill $(cat recv/.pid) && sleep 1 && echo 0 >recv/.exitcode
+# @TEST-EXEC: $SCRIPTS/wait-for-file recv/got-event 30 || (btest-bg-wait -k 1 && false)
+# @TEST-EXEC: kill $(cat recv/.pid)
+# @TEST-EXEC: $SCRIPTS/wait-for-pid $(cat recv/.pid) 10 || (btest-bg-wait -k 1 && false)
+# @TEST-EXEC: echo 0 >recv/.exitcode
+
 # @TEST-EXEC: btest-bg-run recv2 "bro -B broker -b ../recv.bro >recv2.out"
-#
+# @TEST-EXEC: btest-bg-wait 30
-# @TEST-EXEC: btest-bg-wait 25
+
 # @TEST-EXEC: btest-diff send/send.out
 # @TEST-EXEC: btest-diff recv/recv.out
 # @TEST-EXEC: btest-diff recv2/recv2.out
-#
-# @TEST-EXEC: cat send/broker.log | awk '/Broker::STATUS/ { $5="XXX"; print; }' >send/broker.filtered.log
-# @TEST-EXEC: cat recv/broker.log | awk '/Broker::STATUS/ { $5="XXX"; print; }' >recv/broker.filtered.log
-# @TEST-EXEC: cat recv2/broker.log | grep -v "lost remote peer" | awk '/Broker::STATUS/ { $5="XXX"; print; }' >recv2/broker.filtered.log
-# @TEST-EXEC: btest-diff send/broker.filtered.log
-# @TEST-EXEC: btest-diff recv/broker.filtered.log
-# @TEST-EXEC: btest-diff recv2/broker.filtered.log
 
 @TEST-START-FILE send.bro
 
@@ -24,42 +21,34 @@ redef Broker::default_connect_retry=1secs;
 redef Broker::default_listen_retry=1secs;
 redef exit_only_after_terminate = T;
 
-event self_terminate()
+global peers = 0;
+const test_topic = "bro/test/my_topic";
+
+event my_event(i: count)
 	{
-	terminate();
+	print "sender got event", i;
 	}
 
-event do_terminate()
-    {
-    schedule 2sec { self_terminate() };
-    }
-
-event print_something(i: int)
-    {
-    print "Something sender", i;
-    }
-
 event bro_init()
-    {
+	{
-    Broker::subscribe("bro/event/my_topic");
+	Broker::subscribe(test_topic);
-    Broker::auto_publish("bro/event/my_topic", print_something);
+	Broker::peer("127.0.0.1");
-    Broker::auto_publish("bro/event/my_topic", do_terminate);
+	}
-    Broker::peer("127.0.0.1");
-
-    schedule 3secs { print_something(1) };
-    schedule 12secs { print_something(2) };
-    schedule 13secs { do_terminate() };
-    }
 
 event Broker::peer_lost(endpoint: Broker::EndpointInfo, msg: string)
-    {
+	{
-    print "peer lost", msg;
+	print "peer lost", msg;
-    }
+
+	if ( peers == 2 )
+		terminate();
+	}
 
 event Broker::peer_added(endpoint: Broker::EndpointInfo, msg: string)
-    {
+	{
-    print "peer added", msg;
+	++peers;
-    }
+	print "peer added", msg;
+	Broker::publish(test_topic, my_event, peers);
+	}
 
 @TEST-END-FILE
 
@@ -70,31 +59,33 @@ redef Broker::default_connect_retry=1secs;
 redef Broker::default_listen_retry=1secs;
 redef exit_only_after_terminate = T;
 
-event do_terminate()
+const test_topic = "bro/test/my_topic";
-    {
-    terminate();
-    }
 
-event print_something(i: int)
+event my_event(i: count)
-    {
+	{
-    print "Something receiver", i;
+	print "receiver got event", i;
-    }
+
+	if ( i == 1 )
+		# In the first case, terminate via `kill` from btest command.
+		system("touch got-event");
+	else
+		terminate();
+	}
 
 event bro_init()
-    {
+	{
-    Broker::subscribe("bro/event/my_topic");
+	Broker::subscribe(test_topic);
-    Broker::listen("127.0.0.1");
+	Broker::listen("127.0.0.1");
-    }
+	}
 
 event Broker::peer_lost(endpoint: Broker::EndpointInfo, msg: string)
-    {
+	{
-    # In the 2nd run, this may be lost at termination, so don't output.
+	terminate();
-    #print "peer lost", msg;
+	}
-    }
 
 event Broker::peer_added(endpoint: Broker::EndpointInfo, msg: string)
-    {
+	{
-    print "peer added", msg;
+	print "peer added", msg;
-    }
+	}
 
 @TEST-END-FILE

testing/scripts/wait-for-file

@@ -0,0 +1,24 @@
+#! /usr/bin/env bash
+
+# Sleeps until a file comes into existence.
+
+if [[ $# -ne 2 ]]; then
+  >&2 echo "usage: $0 <file to wait for> <max secs to wait>"
+  exit 1
+fi
+
+wait_file=$1
+max_wait=$2
+wait_count=0
+
+while [[ ! -e $wait_file ]]; do
+  let "wait_count += 1"
+
+  if [[ $wait_count -ge $max_wait ]]; then
+    >&2 echo "error: file '$wait_file' does not exist after $max_wait seconds"
+    exit 1
+  fi
+
+  sleep 1
+done
+

testing/scripts/wait-for-pid

@@ -0,0 +1,24 @@
+#! /usr/bin/env bash
+
+# Sleeps until a process id no longer exists.
+
+if [[ $# -ne 2 ]]; then
+  >&2 echo "usage: $0 <pid to wait for> <max secs to wait>"
+  exit 1
+fi
+
+wait_pid=$1
+max_wait=$2
+wait_count=0
+
+while kill -0 $wait_pid &> /dev/null; do
+  let "wait_count += 1"
+
+  if [[ $wait_count -ge $max_wait ]]; then
+    >&2 echo "error: process $wait_pid still exists after $max_wait seconds"
+    exit 1
+  fi
+
+  sleep 1
+done
+