net-test: packetdrill: improve dyanmic tolerance of blocking syscall

Packetdrill calculates the dynamic tolerance based on delta between time
of the last and current event. This delta value is irrelevant for a
blocking system call and the last event is unpredictable and dand epends
on the timing. Instead we can use the delta between the start and end
time specified in the packetdrill with an ellipse.

This change will make some flaky packetdrill tests with a blocking
syscall green.

Signed-off-by: Yousuk Seung <[email protected]>
Change-Id: I0c92ef2003262c6e504f9997cffbc6158b95d53a

Author: yousukseung

gtests/net/packetdrill/run.c

@@ -174,7 +174,7 @@ s64 now_usecs(struct state *state)
  */
 int verify_time(struct state *state, enum event_time_t time_type,
 		s64 script_usecs, s64 script_usecs_end,
-		s64 live_usecs, struct event *last_event,
+		s64 live_usecs, s64 last_event_usecs,
 		const char *description, char **error)
 {
 	s64 expected_usecs = script_usecs - state->script_start_time_usecs;
@@ -189,8 +189,8 @@ int verify_time(struct state *state, enum event_time_t time_type,
 	if (time_type == ANY_TIME)
 		return STATUS_OK;
 
-	if (last_event) {
-		s64 delta = script_usecs - last_event->time_usecs;
+	if (last_event_usecs != NO_TIME_RANGE) {
+		s64 delta = script_usecs - last_event_usecs;
 		long dynamic_tolerance;
 
 		dynamic_tolerance = (state->config->tolerance_percent / 100.0) * delta;
@@ -291,7 +291,7 @@ void check_event_time(struct state *state, s64 live_usecs)
 			state->event->time_usecs,
 			state->event->time_usecs_end,
 			live_usecs,
-			state->last_event,
+			last_event_time_usecs(state),
 			description, &error)) {
 		die("%s:%d: %s\n",
 		    state->config->script_path,

gtests/net/packetdrill/run.h

@@ -154,6 +154,13 @@ static inline s64 live_time_to_script_time_usecs(struct state *state,
 	return script_time_usecs;
 }
 
+/* Get the time of the last event if exists, or NO_TIME_RANGE. */
+static inline s64 last_event_time_usecs(struct state *state)
+{
+	return state->last_event == NULL ? NO_TIME_RANGE :
+			state->last_event->time_usecs;
+}
+
 /*
  * See if something that happened at the given actual live wall time
  * in microseconds happened reasonably close to the time at which we
@@ -167,7 +174,7 @@ static inline s64 live_time_to_script_time_usecs(struct state *state,
  */
 extern int verify_time(struct state *state, enum event_time_t time_type,
 		       s64 script_usecs, s64 script_usecs_end,
-		       s64 live_usecs, struct event *last_event,
+		       s64 live_usecs, s64 last_event_usecs,
 		       const char *description, char **error);
 extern void check_event_time(struct state *state, s64 live_usecs);
 

gtests/net/packetdrill/run_packet.c

@@ -1411,7 +1411,7 @@ static int verify_outbound_live_packet(
 	DEBUGP("packet time_usecs: %lld\n", live_packet->time_usecs);
 	if (verify_time(state, time_type, script_usecs,
 				script_usecs_end, live_packet->time_usecs,
-				state->last_event,
+				last_event_time_usecs(state),
 				"outbound packet", error)) {
 		non_fatal = true;
 		goto out;

gtests/net/packetdrill/run_system_call.c

@@ -3521,13 +3521,18 @@ static void *system_call_thread(void *arg)
 			 */
 			invoke_system_call(state, event, syscall);
 
-			/* Check end time for the blocking system call. */
+			/* Check end time for the blocking system call.
+			 * For a blocking system call we compute the
+			 * dynamic tolerance based on the start and end
+			 * time. The last event here is unpredictable
+			 * and irrelevant.
+			 */
 			assert(state->syscalls->live_end_usecs >= 0);
 			if (verify_time(state,
 						event->time_type,
 						syscall->end_usecs, 0,
 						state->syscalls->live_end_usecs,
-						state->last_event,
+						event->time_usecs,
 						"system call return", &error)) {
 				die("%s:%d: %s\n",
 				    state->config->script_path,