Merge pull request #1109 from grondo/t4011-improvements

testsuite: fix a couple race conditions in `t4011-match-duration.t`

Author: mergify[bot]

resource/modules/resource_match.cpp

@@ -1259,6 +1259,10 @@ static void update_resource (flux_future_t *f, void *arg)
          */
         ctx->db->metadata.graph_duration.graph_end =
             std::chrono::system_clock::from_time_t ((time_t) expiration);
+        flux_log (ctx->h,
+                  LOG_INFO,
+                  "resource expiration updated to %.2f",
+                  expiration);
     }
     for (auto &kv : ctx->notify_msgs) {
         if ( (rc += flux_respond (ctx->h, kv.second->get_msg (), NULL)) < 0) {

t/scripts/dmesg-grep.py

@@ -0,0 +1,69 @@
+#!/usr/bin/env python3
+###############################################################
+# Copyright 2019 Lawrence Livermore National Security, LLC
+# (c.f. AUTHORS, NOTICE.LLNS, COPYING)
+#
+# This file is part of the Flux resource manager framework.
+# For details, see https://github.com/flux-framework.
+#
+# SPDX-License-Identifier: LGPL-3.0
+###############################################################
+#
+#  Follow Flux dmesg output until a line matches a pattern
+#
+import argparse
+import re
+import sys
+
+import flux
+from flux.constants import FLUX_RPC_STREAMING
+from flux.core.watchers import TimerWatcher
+
+parser = argparse.ArgumentParser(
+    description="watch the flux dmesg log for a given pattern"
+)
+parser.add_argument(
+    "-t",
+    "--timeout",
+    help="Timeout with error after some number of seconds",
+    metavar="SEC",
+    type=float,
+    default=1.0,
+)
+parser.add_argument(
+    "-v",
+    "--verbose",
+    help="Emit each line of dmesg output, not just first matching",
+    action="count",
+    default=0,
+)
+parser.add_argument("pattern")
+args = parser.parse_args()
+
+
+def timer_cb(h, watcher, revents, _arg):
+    print("Timeout!", file=sys.stderr)
+    h.reactor_stop_error()
+
+
+def dmesg_cb(rpc, pattern, verbose=False):
+    buf = rpc.get_str()
+    match = pattern.search(buf)
+    if match:
+        print(buf)
+        rpc.flux_handle.reactor_stop()
+    elif verbose:
+        print(buf)
+    rpc.reset()
+
+
+pattern = re.compile(args.pattern)
+
+h = flux.Flux()
+
+rpc = h.rpc("log.dmesg", {"follow": True}, flags=FLUX_RPC_STREAMING)
+rpc.then(dmesg_cb, pattern, verbose=args.verbose)
+
+TimerWatcher(h, args.timeout, timer_cb).start()
+if h.reactor_run() < 0:
+    sys.exit(1)

t/t4011-match-duration.t

@@ -12,6 +12,8 @@ test_under_flux 2
 flux setattr log-stderr-level 1
 export FLUX_URI_RESOLVE_LOCAL=t
 
+dmesg_grep="flux python ${SHARNESS_TEST_SRCDIR}/scripts/dmesg-grep.py"
+
 # Ensure fluxion modules are loaded under flux-alloc(1)
 test_expect_success 'set FLUX_RC_EXTRA so Fluxion modules are loaded under flux-alloc' '
 	mkdir rc1.d &&
@@ -102,7 +104,7 @@ test_expect_success FLUX_UPDATE_RUNNING \
 	id1=$(flux proxy $id flux submit sleep 300) &&
 	duration1=$(subinstance_get_job_duration $id $id1) &&
 	test_debug "echo initial duration of subinstance job1 is $duration1" &&
-	echo $duration1 | jq -e ". < 300" &&
+	echo $duration1 | jq -e ". <= 300" &&
 	test_debug "echo updating duration of alloc job +5m" &&
 	flux update $id duration=+5m &&
 	test_debug "echo waiting for resource-update event" &&
@@ -111,6 +113,8 @@ test_expect_success FLUX_UPDATE_RUNNING \
 	exp2=$(subinstance_get_expiration $id) &&
 	test_debug "echo expiration updated from $exp1 to $exp2" &&
 	echo $exp2 | jq -e ". == $exp1 + 300" &&
+	flux proxy $id $dmesg_grep -vt 30 \
+		\"sched.*resource expiration updated\" &&
 	id2=$(flux proxy $id flux submit sleep 300) &&
 	duration2=$(subinstance_get_job_duration $id $id2) &&
 	test_debug "echo duration of subinstance job2 is $duration2" &&