promise/plugin/check_cpri_lock: Fix it to detect stale data

This promise plugin was using tail_file(self.amarisoft_rf_info_log) to
get the most recent log entry to check. But tail_file simply return last
line of the log file without checking timestamp of returned entry. So it
could be the case that last line is ages ago, reports "CPRI locked ok"
and then, if there are no more rf_info entries for one reason or
another, the CPRI-locked promise will be holding green despite the fact
that data became stale.

-> Fix it by explicitly checking timestamp of last log entry to be in
expected recent range.

/cc @jhuge, @tomo, @xavier_thompson, @Daetalus
/reviewed-by @lu.xu
/reviewed-on !127

slapos/promise/plugin/check_cpri_lock.py

@@ -4,8 +4,7 @@ import logging
 import os
 
 from dateutil import parser
-from .util import JSONPromise
-from .util import tail_file
+from .util import JSONPromise, get_json_log_data_interval
 
 from zope.interface import implementer
 from slapos.grid.promise import interface
@@ -16,7 +15,7 @@ class RunPromise(JSONPromise):
     super(RunPromise, self).__init__(config)
     self.setPeriodicity(minute=1)
     self.amarisoft_rf_info_log = self.getConfig('amarisoft-rf-info-log')
-#    self.stats_period = int(self.getConfig('stats-period'))
+    self.stats_period = int(self.getConfig('stats-period'))
     self.testing = self.getConfig('testing') == "True"
 
   def sense(self):
@@ -24,16 +23,21 @@ class RunPromise(JSONPromise):
           self.logger.info("skipping promise")
           return
   
-      last_line = tail_file(self.amarisoft_rf_info_log)
-      if "CPRI" not in last_line:
+      data_list = get_json_log_data_interval(self.amarisoft_rf_info_log, self.stats_period * 2)
+      if len(data_list) < 1:
+        self.logger.error("rf_info: stale data")
+        return
+
+      rf_info_text = data_list[0]['rf_info']
+      if "CPRI" not in rf_info_text:
           self.logger.info("No CPRI feature")
       else:
-          if "HW" in last_line and "SW" in last_line:
+          if "HW" in rf_info_text and "SW" in rf_info_text:
               self.logger.info("CPRI locked")
           else:
-              if "HW" not in last_line:
+              if "HW" not in rf_info_text:
                   self.logger.error("HW Lock is missing")
-              if "SW" not in last_line:
+              if "SW" not in rf_info_text:
                   self.logger.error("SW Lock is missing")
     
   def test(self):

slapos/test/promise/plugin/test_check_cpri_lock.py

@@ -45,33 +45,38 @@ class TestCheckCpriLock(TestPromisePluginMixin):
     self.amarisoft_rf_info_log = os.path.join(os.path.dirname(os.path.realpath(__file__)), 'amarisoft_rf_info.json.log')
 
 
-  def writeLog(self, data):
+  def writeLog(self, data, ago=5):
     with open(self.amarisoft_rf_info_log, 'w') as f:
       f.write(
       """{"time": "%s", "log_level": "INFO", "message": "RF info", "data": %s}""" %
-        ((datetime.now() - timedelta(seconds=5)).strftime("%Y-%m-%d %H:%M:%S")[:-3], json.dumps(data)))
+        ((datetime.now() - timedelta(seconds=ago)).strftime("%Y-%m-%d %H:%M:%S")[:-3], json.dumps(data)))
 
   def writePromise(self, **kw):
     kw.update({'amarisoft-rf-info-log': self.amarisoft_rf_info_log,
-#              'stats-period':          100,
-    })
+               'stats-period':          100})
     super(TestCheckCpriLock, self).writePromise(self.promise_name,
       "from %s import %s\nextra_config_dict = %r\n"
       % (RunPromise.__module__, RunPromise.__name__, kw))
 
-  def test_promise_success(self):
+  def test_locked_ok(self):
     self.writeLog({'rf_info': "CPRI: x16 HW SW"})
     self.writePromise()
     self.configureLauncher()
     self.launcher.run()
 
-
-  def test_promise_fail(self):
+  def test_no_lock(self):
     self.writeLog({'rf_info': "CPRI: x16\\n"})
     self.writePromise()
     self.configureLauncher()
     with self.assertRaises(PromiseError):
       self.launcher.run()
 
+  def test_stale_data(self):
+    self.writeLog({'rf_info': "CPRI: x16 HW SW"}, ago=500)
+    self.writePromise()
+    self.configureLauncher()
+    with self.assertRaisesRegex(PromiseError, 'rf_info: stale data'):
+      self.launcher.run()
+
 if __name__ == '__main__':
   unittest.main()