The enabling and disabling of warning messages unfortunately seems to

be rather racy. Unfortunately, since warnings and test status messages
are being pulled asynchronously from two different sources there can
be a skew of a few seconds between when the event actually occurs
and when the server thinks it does.

Ideally we could fix this by forcing some kind of sync but there
doesn't seem to be any way of doing that; we have no way of flushing
conmux output, and /var/log monitoring is even worse since we may
also have client filesystem buffering getting in the way.

I was able to fix all the cases I could reproduce by adding a five
second sleep before and after disabling and enabling warnings. This is
an...unfortunate way to fix it, but in practice it works rather well.
I'm not actually certain we can do a lot better, at least not without
completely restructuring the way we do warnings. And even then, we
still have network latency that can kill any approach that doesn't
use a "sleep for a moments while the buffers flush" anyway.

Hopefully this fixes things well enough; if this problems comes up
again thanks to > 5s skews then we may have to revisit this.

Risk: Low
Visibility: Adds some sleep to hack around warning monitor and
client status log time skew.

Signed-off-by: John Admanski <jadmanski@google.com>



git-svn-id: svn://test.kernel.org/autotest/trunk@2950 592f7852-d20e-0410-864c-8624ca9c26a4

1 files changed, 3 insertions, 0 deletions

diff --git a/client/bin/job.py b/client/bin/job.py
index bf958f28..467c51e8 100755
--- a/client/bin/job.py
+++ b/client/bin/job.py
@@ -91,6 +91,7 @@ class base_job(object):
     """
 
     DEFAULT_LOG_FILENAME = "status"
+    WARNING_DISABLE_DELAY = 5
 
     def __init__(self, control, jobtag, cont, harness_type=None,
                  use_external_logging=False, drop_caches=True):
@@ -230,9 +231,11 @@ class base_job(object):
         self.record("INFO", None, None,
                     "disabling %s warnings" % warning_type,
                     {"warnings.disable": warning_type})
+        time.sleep(self.WARNING_DISABLE_DELAY)
 
 
     def enable_warnings(self, warning_type):
+        time.sleep(self.WARNING_DISABLE_DELAY)
         self.record("INFO", None, None,
                     "enabling %s warnings" % warning_type,
                     {"warnings.enable": warning_type})