Repository: dmwm/wmcore
Issue: Workflows stuck in announced status for a year

**Impact of the bug**
Likely MSRuleCleaner

**Describe the bug**
While scanning the system for very old workflows, I found a small set of workflows from 2020 that have been sitting in `announced` status for many months, maybe even for a year or more. Here is the list [1].

**How to reproduce it**
None

**Expected behavior**
Workflow archival should be done at the MSRuleCleaner microservice, so we should investigate its logs in production and try to understand why these workflows are still in announced. There could be some implemented constraints which are keeping these workflows in this state, but we should understand what those are and make sure there are no subtle issues with the workflow archival.

**Additional context and error message**
[1]
```
cmsunified_task_B2G-RunIISummer20UL17wmLHEGEN-00399__v1_T_201217_220835_930
cmsunified_task_B2G-RunIISummer20UL17wmLHEGEN-00417__v1_T_201217_222725_8395
cmsunified_task_B2G-RunIISummer20UL17wmLHEGEN-00420__v1_T_201217_223216_3726
cmsunified_task_B2G-RunIISummer20UL17wmLHEGEN-00427__v1_T_201217_215709_6988
cmsunified_task_B2G-RunIISummer20UL17wmLHEGEN-00453__v1_T_201217_224624_965
cmsunified_task_B2G-RunIISummer20UL17wmLHEGEN-00458__v1_T_201217_214406_3495
cmsunified_task_B2G-RunIISummer20UL17wmLHEGEN-00475__v1_T_201217_225614_2162
cmsunified_task_B2G-RunIISummer20UL17wmLHEGEN-00488__v1_T_201217_222701_445
cmsunified_task_TOP-RunIISummer20UL17wmLHEGEN-00056__v1_T_201210_105536_8824
cmsunified_task_TOP-RunIISummer20UL17wmLHEGEN-00058__v1_T_201210_110637_9543
cmsunified_task_TOP-RunIISummer20UL17wmLHEGEN-00065__v1_T_201221_155242_4539
cmsunified_task_TOP-RunIISummer20UL18wmLHEGEN-00037__v1_T_201207_122800_6254
cmsunified_task_TOP-RunIISummer20UL18wmLHEGEN-00057__v1_T_201206_222426_2907
```

Changed files:
src/python/WMCore/MicroService/MSRuleCleaner/MSRuleCleaner.py, test/python/WMCore_t/MicroService_t/MSRuleCleaner_t/MSRuleCleaner_t.py

diff --git a/src/python/WMCore/MicroService/MSRuleCleaner/MSRuleCleaner.py b/src/python/WMCore/MicroService/MSRuleCleaner/MSRuleCleaner.py
index ed9598068..286ade740 100644
--- a/src/python/WMCore/MicroService/MSRuleCleaner/MSRuleCleaner.py
+++ b/src/python/WMCore/MicroService/MSRuleCleaner/MSRuleCleaner.py
@@ -85,6 +85,9 @@ class MSRuleCleaner(MSCore):
         self.msConfig.setdefault("rucioWmaAccount", "wma_test")
         self.msConfig.setdefault("rucioMStrAccount", "wmcore_transferor")
         self.msConfig.setdefault('enableRealMode', False)
+        self.msConfig.setdefault('archiveDelayHours', 24 * 2)
+        self.msConfig.setdefault('archiveAlarmHours', 24 * 30)
+        self.msConfig.setdefault("sendNotification", False)
 
         self.currThread = None
         self.currThreadIdent = None
@@ -316,37 +319,42 @@ class MSRuleCleaner(MSCore):
         elif wflow['RequestStatus'] == 'announced' and not wflow['ParentageResolved']:
             # NOTE: We skip workflows which are not having 'ParentageResolved'
             #       flag, but we still need some proper logging for them.
-            msg = "Skipping workflow: %s - 'ParentageResolved' flag set to false."
+            msg = "Skipping workflow: %s - 'ParentageResolved' flag set to false." % wflow['RequestName']
             msg += " Will retry again in the next cycle."
-            self.logger.info(msg, wflow['RequestName'])
+            self.logger.info(msg)
+            self.alertStatusAdvanceExpired(wflow, additionalInfo=msg)
         elif wflow['RequestStatus'] == 'announced' and not wflow['TransferDone']:
             # NOTE: We skip workflows which have not yet finalised their TransferStatus
             #       in MSOutput, but we still need some proper logging for them.
-            msg = "Skipping workflow: %s - 'TransferStatus' is 'pending' or 'TransferInfo' is missing in MSOutput."
+            msg = "Skipping workflow: %s - 'TransferStatus' is 'pending' or 'TransferInfo' is missing in MSOutput." % wflow['RequestName']
             msg += " Will retry again in the next cycle."
-            self.logger.info(msg, wflow['RequestName'])
+            self.logger.info(msg)
+            self.alertStatusAdvanceExpired(wflow, additionalInfo=msg)
         elif wflow['RequestStatus'] == 'announced' and not wflow['TransferTape']:
             # NOTE: We skip workflows which have not yet finalised their tape transfers.
             #       (i.e. even if a single output which is supposed to be covered
             #       by a tape rule is in any of the following transient states:
             #       {REPLICATING, STUCK, SUSPENDED, WAITING_APPROVAL}.)
             #       We still need some proper logging for them.
-            msg = "Skipping workflow: %s - tape transfers are not yet completed."
+            msg = "Skipping workflow: %s - tape transfers are not yet completed." % wflow['RequestName']
             msg += " Will retry again in the next cycle."
-            self.logger.info(msg, wflow['RequestName'])
+            self.logger.info(msg)
+            self.alertStatusAdvanceExpired(wflow, additionalInfo=msg)
         elif wflow['RequestStatus'] == 'announced':
             for pline in self.cleanuplines:
                 try:
                     pline.run(wflow)
                 except MSRuleCleanerResolveParentError as ex:
-                    msg = "%s: Parentage Resolve Error: %s. "
+                    msg = "%s: Parentage Resolve Error: %s. " % (pline.name, str(ex))
                     msg += "Will retry again in the next cycle."
-                    self.logger.error(msg, pline.name, str(ex))
+                    self.logger.error(msg)
+                    self.alertStatusAdvanceExpired(wflow, additionalInfo=msg)
                     continue
                 except Exception as ex:
-                    msg = "%s: General error from pipeline. Workflow: %s. Error:  \\n%s. "
+                    msg = "%s: General error from pipeline. Workflow: %s. Error:  \\n%s. " % (pline.name, wflow['RequestName'], str(ex))
                     msg += "\\nWill retry again in the next cycle."
-                    self.logger.exception(msg, pline.name, wflow['RequestName'], str(ex))
+                    self.logger.exception(msg)
+                    self.alertStatusAdvanceExpired(wflow, additionalInfo=msg)
                     continue
                 if wflow['CleanupStatus'][pline.name]:
                     self.wfCounters['cleaned'][pline.name] += 1
@@ -404,6 +412,37 @@ class MSRuleCleaner(MSCore):
                 wflow['CleanupStatus'][pName] = False
         return wflow
 
+    def _getLastStatusTransitionTime(self, wflow):
+        """
+        A method to return status transition time for a workflow.
+        :param wflow:  A MSRuleCleanerWorkflow instance
+        :return:       The UTC timestamp for the transition if it exists, None otherwise
+        """
+        try:
+            for trans in wflow['RequestTransition'][::-1]:
+                if trans['Status'] == wflow['RequestStatus']:
+                    return trans['UpdateTime']
+        except KeyError:
+            self.logger.error("Missing or broken status transition history for %s", wflow['RequestName'])
+            return None
+
+    def _isStatusAdvanceExpired(self, wflow):
+        """
+        A method to check if a given status transition has timed out e.g. before
+        an alarm being set. The timeout should be configurable and hence taken
+        from the instance attributes.
+        :param wflow:  A MSRuleCleanerWorkflow instance
+        :return:       Bool: True if status alarm time has expired False otherwise
+        """
+        statusAdvanceExpired = False
+        currentTime = int(time.time())
+        alarmThreshold = self.msConfig['archiveAlarmHours'] * 3600
+        transitionTime = self._getLastStatusTransitionTime(wflow)
+
+        if transitionTime and (currentTime - transitionTime) > alarmThreshold:
+            statusAdvanceExpired = True
+        return statusAdvanceExpired
+
     def _checkClean(self, wflow):
         """
         An auxiliary function used to only check the temporary cleanup status.
@@ -520,12 +559,9 @@ class MSRuleCleaner(MSCore):
         archDelayExpired = False
         currentTime = int(time.time())
         threshold = self.msConfig['archiveDelayHours'] * 3600
-        try:
-            lastTransitionTime = wflow['RequestTransition'][-1]['UpdateTime']
-            if lastTransitionTime and (currentTime - lastTransitionTime) > threshold:
-                archDelayExpired = True
-        except KeyError:
-            self.logger.debug("Could not find status transition history for %s", wflow['RequestName'])
+        lastTransitionTime = self._getLastStatusTransitionTime(wflow)
+        if lastTransitionTime and (currentTime - lastTransitionTime) > threshold:
+            archDelayExpired = True
         return archDelayExpired
 
     def setArchivalDelayExpired(self, wflow):
@@ -545,12 +581,15 @@ class MSRuleCleaner(MSCore):
         # Make all the needed checks before trying to archive
         if not (wflow['IsClean'] or wflow['ForceArchive']):
             msg = "Not properly cleaned workflow: %s" % wflow['RequestName']
+            self.alertStatusAdvanceExpired(wflow, additionalInfo=msg)
             raise MSRuleCleanerArchivalSkip(msg)
         if not wflow['TargetStatus']:
             msg = "Could not determine which archival status to target for workflow: %s" % wflow['RequestName']
+            self.alertStatusAdvanceExpired(wflow, additionalInfo=msg)
             raise MSRuleCleanerArchivalError(msg)
         if not wflow['IsLogDBClean']:
             msg = "LogDB records have not been cleaned for workflow: %s" % wflow['RequestName']
+            self.alertStatusAdvanceExpired(wflow, additionalInfo=msg)
             raise MSRuleCleanerArchivalSkip(msg)
         if not wflow['IsArchivalDelayExpired']:
             msg = "Archival delay period has not yet expired for workflow: %s." % wflow['RequestName']
@@ -761,7 +800,39 @@ class MSRuleCleaner(MSCore):
         alertDescription = "Workflow: {} has the following pileup container ".format(workflowName)
         alertDescription += "\\n{}\\n no longer in the global locks. ".format(containerName)
         alertDescription += "These rules\\n{}\\nare eligible for deletion.".format(ruleList)
-        # alert to expiry in 2 days
-        self.sendAlert(alertName, alertSeverity, alertSummary, alertDescription,
-                       service=self.alertServiceName, endSecs=self.alertExpiration)
+
+        # Check if alarms are enabled for this service
+        # Alert expiration time defaults to 2 days
+        if self.msConfig["sendNotification"]:
+            self.sendAlert(alertName, alertSeverity, alertSummary, alertDescription,
+                           service=self.alertServiceName, endSecs=self.alertExpiration)
+        self.logger.critical(alertDescription)
+
+    def alertStatusAdvanceExpired(self, wflow, additionalInfo=None):
+        """
+        Send alert notifying that a workflow has spend too much time in a given status
+        :param wflow: MSRuleCleanerWorkflow instance
+        :additionalInfo: String with additional information.
+        :return: none
+        """
+        # Check if alarm threshold has expired:
+        if not self._isStatusAdvanceExpired(wflow):
+            return
+        lastTransitionTime = self._getLastStatusTransitionTime(wflow)
+        alertName = "{}: Not archived workflow: {}".format(self.alertServiceName, wflow['RequestName'])
+        alertSeverity = "high"
+        alertDescription = "Found a workflow not archived since {}.".format(time.ctime(lastTransitionTime))
+        alertDescription += "\\nWorkflow: {}".format(wflow['RequestName'])
+        alertDescription += "\\nHas exceeded the Status Advance Timeout of: {} hours".format(self.msConfig['archiveAlarmHours'])
+        alertDescription += " for its current status: {}.".format(wflow['RequestStatus'])
+        if additionalInfo:
+            alertDescription += "\\nAdditional info: {}".format(additionalInfo)
+        alertDescription += "\\nActions need to be taken!"
+        alertSummary = "[MSRuleCleaner] Found workflow: {} not archived since {}.".format(wflow['RequestName'], time.ctime(lastTransitionTime))
+
+        # Check if alarms are enabled for this service
+        # Alert expiration time defaults to 2 days
+        if self.msConfig["sendNotification"]:
+            self.sendAlert(alertName, alertSeverity, alertSummary, alertDescription,
+                           service=self.alertServiceName, endSecs=self.alertExpiration)
         self.logger.critical(alertDescription)
diff --git a/test/python/WMCore_t/MicroService_t/MSRuleCleaner_t/MSRuleCleaner_t.py b/test/python/WMCore_t/MicroService_t/MSRuleCleaner_t/MSRuleCleaner_t.py
index d377c3a6e..98425aa41 100644
--- a/test/python/WMCore_t/MicroService_t/MSRuleCleaner_t/MSRuleCleaner_t.py
+++ b/test/python/WMCore_t/MicroService_t/MSRuleCleaner_t/MSRuleCleaner_t.py
@@ -2,6 +2,8 @@
 Unit tests for Unified/MSRuleCleaner.py module
 
 """
+# pylint: disable=W0212
+
 from __future__ import division, print_function
 
 import json
@@ -46,6 +48,7 @@ class MSRuleCleanerTest(unittest.TestCase):
                          "logDBUrl": "https://cmsweb-testbed.cern.ch/couchdb/wmstats_logdb",
                          'logDBReporter': 'reqmgr2ms_ruleCleaner',
                          'archiveDelayHours': 8,
+                         'archiveAlarmHours': 24,
                          'enableRealMode': False}
 
         self.creds = {"client_cert": os.getenv("X509_USER_CERT", "Unknown"),
@@ -70,14 +73,23 @@ class MSRuleCleanerTest(unittest.TestCase):
         self.taskChainFile = getTestFile('data/ReqMgr/requests/Static/TaskChainRequestDump.json')
         self.stepChainFile = getTestFile('data/ReqMgr/requests/Static/StepChainRequestDump.json')
         self.reqRecordsFile = getTestFile('data/ReqMgr/requests/Static/BatchRequestsDump.json')
-        with open(self.reqRecordsFile) as fd:
+        with open(self.reqRecordsFile, encoding="utf-8") as fd:
             self.reqRecords = json.load(fd)
-        with open(self.taskChainFile) as fd:
+        with open(self.taskChainFile, encoding="utf-8") as fd:
             self.taskChainReq = json.load(fd)
-        with open(self.stepChainFile) as fd:
+        with open(self.stepChainFile, encoding="utf-8") as fd:
             self.stepChainReq = json.load(fd)
         super(MSRuleCleanerTest, self).setUp()
 
+    def testGetLastStatusTransitionTime(self):
+        wflow = MSRuleCleanerWflow(self.taskChainReq)
+        lastStatusTransition = self.msRuleCleaner._getLastStatusTransitionTime(wflow)
+        self.assertEqual(lastStatusTransition, 1607359514)
+
+    def testIsStatusAdvanceExpired(self):
+        wflow = MSRuleCleanerWflow(self.taskChainReq)
+        self.assertTrue(self.msRuleCleaner._isStatusAdvanceExpired(wflow))
+
     def testPipelineAgentBlock(self):
         # Test plineAgentBlock:
         wflow = MSRuleCleanerWflow(self.taskChainReq)
@@ -86,36 +98,36 @@ class MSRuleCleanerTest(unittest.TestCase):
                          'DataPileup': [],
                          'ForceArchive': False,
                          'IncludeParents': False,
-                         'InputDataset': u'/JetHT/Run2012C-v1/RAW',
+                         'InputDataset': '/JetHT/Run2012C-v1/RAW',
                          'IsArchivalDelayExpired': False,
                          'IsClean': False,
                          'IsLogDBClean': False,
                          'MCPileup': [],
                          'OutputDatasets': [
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
                          'ParentDataset': [],
                          'ParentageResolved': True,
                          'PlineMarkers': ['plineAgentBlock'],
-                         'RequestName': u'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
-                         'RequestStatus': u'announced',
-                         'RequestTransition': [{u'DN': u'', u'Status': u'new', u'UpdateTime': 1606723304},
-                                               {u'DN': u'', u'Status': u'assignment-approved',
-                                                u'UpdateTime': 1606723305},
-                                               {u'DN': u'', u'Status': u'assigned', u'UpdateTime': 1606723306},
-                                               {u'DN': u'', u'Status': u'staging', u'UpdateTime': 1606723461},
-                                               {u'DN': u'', u'Status': u'staged', u'UpdateTime': 1606723590},
-                                               {u'DN': u'', u'Status': u'acquired', u'UpdateTime': 1606723968},
-                                               {u'DN': u'', u'Status': u'running-open', u'UpdateTime': 1606724572},
-                                               {u'DN': u'', u'Status': u'running-closed', u'UpdateTime': 1606724573},
-                                               {u'DN': u'', u'Status': u'completed', u'UpdateTime': 1607018413},
-                                               {u'DN': u'', u'Status': u'closed-out', u'UpdateTime': 1607347706},
-                                               {u'DN': u'', u'Status': u'announced', u'UpdateTime': 1607359514}],
-                         'RequestType': u'TaskChain',
-                         'SubRequestType': u'',
+                         'RequestName': 'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
+                         'RequestStatus': 'announced',
+                         'RequestTransition': [{'DN': '', 'Status': 'new', 'UpdateTime': 1606723304},
+                                               {'DN': '', 'Status': 'assignment-approved',
+                                                'UpdateTime': 1606723305},
+                                               {'DN': '', 'Status': 'assigned', 'UpdateTime': 1606723306},
+                                               {'DN': '', 'Status': 'staging', 'UpdateTime': 1606723461},
+                                               {'DN': '', 'Status': 'staged', 'UpdateTime': 1606723590},
+                                               {'DN': '', 'Status': 'acquired', 'UpdateTime': 1606723968},
+                                               {'DN': '', 'Status': 'running-open', 'UpdateTime': 1606724572},
+                                               {'DN': '', 'Status': 'running-closed', 'UpdateTime': 1606724573},
+                                               {'DN': '', 'Status': 'completed', 'UpdateTime': 1607018413},
+                                               {'DN': '', 'Status': 'closed-out', 'UpdateTime': 1607347706},
+                                               {'DN': '', 'Status': 'announced', 'UpdateTime': 1607359514}],
+                         'RequestType': 'TaskChain',
+                         'SubRequestType': '',
                          'RulesToClean': {'plineAgentBlock': []},
                          'TargetStatus': None,
                          'TransferDone': False,
@@ -130,36 +142,36 @@ class MSRuleCleanerTest(unittest.TestCase):
                          'DataPileup': [],
                          'ForceArchive': False,
                          'IncludeParents': False,
-                         'InputDataset': u'/JetHT/Run2012C-v1/RAW',
+                         'InputDataset': '/JetHT/Run2012C-v1/RAW',
                          'IsArchivalDelayExpired': False,
                          'IsClean': False,
                          'IsLogDBClean': False,
                          'MCPileup': [],
                          'OutputDatasets': [
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
                          'ParentDataset': [],
                          'ParentageResolved': True,
                          'PlineMarkers': ['plineAgentCont'],
-                         'RequestName': u'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
-                         'RequestStatus': u'announced',
-                         'RequestTransition': [{u'DN': u'', u'Status': u'new', u'UpdateTime': 1606723304},
-                                               {u'DN': u'', u'Status': u'assignment-approved',
-                                                u'UpdateTime': 1606723305},
-                                               {u'DN': u'', u'Status': u'assigned', u'UpdateTime': 1606723306},
-                                               {u'DN': u'', u'Status': u'staging', u'UpdateTime': 1606723461},
-                                               {u'DN': u'', u'Status': u'staged', u'UpdateTime': 1606723590},
-                                               {u'DN': u'', u'Status': u'acquired', u'UpdateTime': 1606723968},
-                                               {u'DN': u'', u'Status': u'running-open', u'UpdateTime': 1606724572},
-                                               {u'DN': u'', u'Status': u'running-closed', u'UpdateTime': 1606724573},
-                                               {u'DN': u'', u'Status': u'completed', u'UpdateTime': 1607018413},
-                                               {u'DN': u'', u'Status': u'closed-out', u'UpdateTime': 1607347706},
-                                               {u'DN': u'', u'Status': u'announced', u'UpdateTime': 1607359514}],
-                         'RequestType': u'TaskChain',
-                         'SubRequestType': u'',
+                         'RequestName': 'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
+                         'RequestStatus': 'announced',
+                         'RequestTransition': [{'DN': '', 'Status': 'new', 'UpdateTime': 1606723304},
+                                               {'DN': '', 'Status': 'assignment-approved',
+                                                'UpdateTime': 1606723305},
+                                               {'DN': '', 'Status': 'assigned', 'UpdateTime': 1606723306},
+                                               {'DN': '', 'Status': 'staging', 'UpdateTime': 1606723461},
+                                               {'DN': '', 'Status': 'staged', 'UpdateTime': 1606723590},
+                                               {'DN': '', 'Status': 'acquired', 'UpdateTime': 1606723968},
+                                               {'DN': '', 'Status': 'running-open', 'UpdateTime': 1606724572},
+                                               {'DN': '', 'Status': 'running-closed', 'UpdateTime': 1606724573},
+                                               {'DN': '', 'Status': 'completed', 'UpdateTime': 1607018413},
+                                               {'DN': '', 'Status': 'closed-out', 'UpdateTime': 1607347706},
+                                               {'DN': '', 'Status': 'announced', 'UpdateTime': 1607359514}],
+                         'RequestType': 'TaskChain',
+                         'SubRequestType': '',
                          'RulesToClean': {'plineAgentCont': []},
                          'TargetStatus': None,
                          'TransferDone': False,
@@ -174,38 +186,38 @@ class MSRuleCleanerTest(unittest.TestCase):
                          'DataPileup': [],
                          'ForceArchive': False,
                          'IncludeParents': False,
-                         'InputDataset': u'/JetHT/Run2012C-v1/RAW',
+                         'InputDataset': '/JetHT/Run2012C-v1/RAW',
                          'IsArchivalDelayExpired': False,
                          'IsClean': False,
                          'IsLogDBClean': False,
                          'MCPileup': [],
                          'OutputDatasets': [
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
                          'ParentDataset': [],
                          'ParentageResolved': True,
                          'PlineMarkers': ['plineMSTrBlock'],
-                         'RequestName': u'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
-                         'RequestStatus': u'announced',
-                         'RequestTransition': [{u'DN': u'',
-                                                u'Status': u'new',
-                                                u'UpdateTime': 1606723304},
-                                               {u'DN': u'', u'Status': u'assignment-approved',
-                                                u'UpdateTime': 1606723305},
-                                               {u'DN': u'', u'Status': u'assigned', u'UpdateTime': 1606723306},
-                                               {u'DN': u'', u'Status': u'staging', u'UpdateTime': 1606723461},
-                                               {u'DN': u'', u'Status': u'staged', u'UpdateTime': 1606723590},
-                                               {u'DN': u'', u'Status': u'acquired', u'UpdateTime': 1606723968},
-                                               {u'DN': u'', u'Status': u'running-open', u'UpdateTime': 1606724572},
-                                               {u'DN': u'', u'Status': u'running-closed', u'UpdateTime': 1606724573},
-                                               {u'DN': u'', u'Status': u'completed', u'UpdateTime': 1607018413},
-                                               {u'DN': u'', u'Status': u'closed-out', u'UpdateTime': 1607347706},
-                                               {u'DN': u'', u'Status': u'announced', u'UpdateTime': 1607359514}],
-                         'RequestType': u'TaskChain',
-                         'SubRequestType': u'',
+                         'RequestName': 'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
+                         'RequestStatus': 'announced',
+                         'RequestTransition': [{'DN': '',
+                                                'Status': 'new',
+                                                'UpdateTime': 1606723304},
+                                               {'DN': '', 'Status': 'assignment-approved',
+                                                'UpdateTime': 1606723305},
+                                               {'DN': '', 'Status': 'assigned', 'UpdateTime': 1606723306},
+                                               {'DN': '', 'Status': 'staging', 'UpdateTime': 1606723461},
+                                               {'DN': '', 'Status': 'staged', 'UpdateTime': 1606723590},
+                                               {'DN': '', 'Status': 'acquired', 'UpdateTime': 1606723968},
+                                               {'DN': '', 'Status': 'running-open', 'UpdateTime': 1606724572},
+                                               {'DN': '', 'Status': 'running-closed', 'UpdateTime': 1606724573},
+                                               {'DN': '', 'Status': 'completed', 'UpdateTime': 1607018413},
+                                               {'DN': '', 'Status': 'closed-out', 'UpdateTime': 1607347706},
+                                               {'DN': '', 'Status': 'announced', 'UpdateTime': 1607359514}],
+                         'RequestType': 'TaskChain',
+                         'SubRequestType': '',
                          'RulesToClean': {'plineMSTrBlock': []},
                          'TargetStatus': None,
                          'TransferDone': False,
@@ -220,38 +232,38 @@ class MSRuleCleanerTest(unittest.TestCase):
                          'DataPileup': [],
                          'ForceArchive': False,
                          'IncludeParents': False,
-                         'InputDataset': u'/JetHT/Run2012C-v1/RAW',
+                         'InputDataset': '/JetHT/Run2012C-v1/RAW',
                          'IsArchivalDelayExpired': False,
                          'IsClean': False,
                          'IsLogDBClean': False,
                          'MCPileup': [],
                          'OutputDatasets': [
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
                          'ParentDataset': [],
                          'ParentageResolved': True,
                          'PlineMarkers': ['plineMSTrCont'],
-                         'RequestName': u'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
-                         'RequestStatus': u'announced',
-                         'RequestTransition': [{u'DN': u'',
-                                                u'Status': u'new',
-                                                u'UpdateTime': 1606723304},
-                                               {u'DN': u'', u'Status': u'assignment-approved',
-                                                u'UpdateTime': 1606723305},
-                                               {u'DN': u'', u'Status': u'assigned', u'UpdateTime': 1606723306},
-                                               {u'DN': u'', u'Status': u'staging', u'UpdateTime': 1606723461},
-                                               {u'DN': u'', u'Status': u'staged', u'UpdateTime': 1606723590},
-                                               {u'DN': u'', u'Status': u'acquired', u'UpdateTime': 1606723968},
-                                               {u'DN': u'', u'Status': u'running-open', u'UpdateTime': 1606724572},
-                                               {u'DN': u'', u'Status': u'running-closed', u'UpdateTime': 1606724573},
-                                               {u'DN': u'', u'Status': u'completed', u'UpdateTime': 1607018413},
-                                               {u'DN': u'', u'Status': u'closed-out', u'UpdateTime': 1607347706},
-                                               {u'DN': u'', u'Status': u'announced', u'UpdateTime': 1607359514}],
-                         'RequestType': u'TaskChain',
-                         'SubRequestType': u'',
+                         'RequestName': 'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
+                         'RequestStatus': 'announced',
+                         'RequestTransition': [{'DN': '',
+                                                'Status': 'new',
+                                                'UpdateTime': 1606723304},
+                                               {'DN': '', 'Status': 'assignment-approved',
+                                                'UpdateTime': 1606723305},
+                                               {'DN': '', 'Status': 'assigned', 'UpdateTime': 1606723306},
+                                               {'DN': '', 'Status': 'staging', 'UpdateTime': 1606723461},
+                                               {'DN': '', 'Status': 'staged', 'UpdateTime': 1606723590},
+                                               {'DN': '', 'Status': 'acquired', 'UpdateTime': 1606723968},
+                                               {'DN': '', 'Status': 'running-open', 'UpdateTime': 1606724572},
+                                               {'DN': '', 'Status': 'running-closed', 'UpdateTime': 1606724573},
+                                               {'DN': '', 'Status': 'completed', 'UpdateTime': 1607018413},
+                                               {'DN': '', 'Status': 'closed-out', 'UpdateTime': 1607347706},
+                                               {'DN': '', 'Status': 'announced', 'UpdateTime': 1607359514}],
+                         'RequestType': 'TaskChain',
+                         'SubRequestType': '',
                          'RulesToClean': {'plineMSTrCont': []},
                          'TargetStatus': None,
                          'TransferDone': False,
@@ -277,39 +289,39 @@ class MSRuleCleanerTest(unittest.TestCase):
                          'DataPileup': [],
                          'ForceArchive': False,
                          'IncludeParents': False,
-                         'InputDataset': u'/JetHT/Run2012C-v1/RAW',
+                         'InputDataset': '/JetHT/Run2012C-v1/RAW',
                          'IsArchivalDelayExpired': True,
                          'IsClean': True,
                          'IsLogDBClean': True,
                          'MCPileup': [],
                          'OutputDatasets': [
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
-                             u'/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
-                             u'/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/RECO',
+                             '/JetHT/CMSSW_7_2_0-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/DQMIO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-SiStripCalZeroBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO',
+                             '/JetHT/CMSSW_7_2_0-TkAlMinBias-RECODreHLT_TaskChain_LumiMask_multiRun_HG2011_Val_Todor_v1-v11/ALCARECO'],
                          'ParentDataset': [],
                          'ParentageResolved': True,
                          'PlineMarkers': ['plineArchive',
                                           'plineAgentBlock',
                                           'plineAgentCont',
                                           'plineArchive'],
-                         'RequestName': u'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
-                         'RequestStatus': u'announced',
-                         'RequestTransition': [{u'DN': u'', u'Status': u'new', u'UpdateTime': 1606723304},
-                                               {u'DN': u'', u'Status': u'assignment-approved',
-                                                u'UpdateTime': 1606723305},
-                                               {u'DN': u'', u'Status': u'assigned', u'UpdateTime': 1606723306},
-                                               {u'DN': u'', u'Status': u'staging', u'UpdateTime': 1606723461},
-                                               {u'DN': u'', u'Status': u'staged', u'UpdateTime': 1606723590},
-                                               {u'DN': u'', u'Status': u'acquired', u'UpdateTime': 1606723968},
-                                               {u'DN': u'', u'Status': u'running-open', u'UpdateTime': 1606724572},
-                                               {u'DN': u'', u'Status': u'running-closed', u'UpdateTime': 1606724573},
-                                               {u'DN': u'', u'Status': u'completed', u'UpdateTime': 1607018413},
-                                               {u'DN': u'', u'Status': u'closed-out', u'UpdateTime': 1607347706},
-                                               {u'DN': u'', u'Status': u'announced', u'UpdateTime': 1607359514}],
-                         'RequestType': u'TaskChain',
-                         'SubRequestType': u'',
+                         'RequestName': 'TaskChain_LumiMask_multiRun_HG2011_Val_201029_112735_5891',
+                         'RequestStatus': 'announced',
+                         'RequestTransition': [{'DN': '', 'Status': 'new', 'UpdateTime': 1606723304},
+                                               {'DN': '', 'Status': 'assignment-approved',
+                                                'UpdateTime': 1606723305},
+                                               {'DN': '', 'Status': 'assigned', 'UpdateTime': 1606723306},
+                                               {'DN': '', 'Status': 'staging', 'UpdateTime': 1606723461},
+                                               {'DN': '', 'Status': 'staged', 'UpdateTime': 1606723590},
+                                               {'DN': '', 'Status': 'acquired', 'UpdateTime': 1606723968},
+                                               {'DN': '', 'Status': 'running-open', 'UpdateTime': 1606724572},
+                                               {'DN': '', 'Status': 'running-closed', 'UpdateTime': 1606724573},
+                                               {'DN': '', 'Status': 'completed', 'UpdateTime': 1607018413},
+                                               {'DN': '', 'Status': 'closed-out', 'UpdateTime': 1607347706},
+                                               {'DN': '', 'Status': 'announced', 'UpdateTime': 1607359514}],
+                         'RequestType': 'TaskChain',
+                         'SubRequestType': '',
                          'RulesToClean': {'plineAgentBlock': [], 'plineAgentCont': []},
                          'TargetStatus': 'normal-archived',
                          'TransferDone': False,