Merge pull request #11692 from vkuznet/fix-issue-11660-wma

Add WMCMSSWSubprocess and WMTiming metrics to WMArchvie document
dmwm · Aug 24, 2023 · 523b400 · 523b400
2 parents b8905db + 7d9a152
commit 523b400
Show file tree

Hide file tree

Showing 16 changed files with 119 additions and 8 deletions.
diff --git a/src/python/WMCore/Services/WMArchive/DataMap.py b/src/python/WMCore/Services/WMArchive/DataMap.py
@@ -60,6 +60,8 @@
  'errors': [],
  'input': [],
  'output': [],
+ 'WMCMSSWSubprocess': {},
+ 'WMTiming': {},
  'performance': {}
  }
 
@@ -110,6 +112,8 @@
  # "GUID": '',
  # 'StageOutCommand': ''
  }],
+ 'WMCMSSWSubprocess': {},
+ 'WMTiming': {},
  'performance': {'cpu': {},
  'memory': {},
  'multicore': {},

diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/DataMap_t.py b/test/python/WMCore_t/Services_t/WMArchive_t/DataMap_t.py
@@ -9,6 +9,11 @@
 SAMPLE_FWJR = {'fallbackFiles': [],
  'skippedFiles': [],
  'steps': {'cmsRun1': {'analysis': {},
+ 'WMCMSSWSubprocess': {'endTime': 1692718964.7409143,
+ 'startTime': 1692712699.8846245,
+ 'sysTime': 94.256681,
+ 'userTime': 6053.7735170000005,
+ 'wallClockTime': 6264.856289863586},
  'cleanup': {},
  'errors': [],
  'input': {'source': [{'catalog': '',
@@ -161,6 +166,9 @@
  'start': 1454569727,
  'status': 0,
  'stop': 1454569735}},
+ 'WMTiming': {'WMJobStart': 1692712699.8846245,
+ 'WMJobEnd': 1692718964.7409143,
+ 'WMTotalWallClockTime': 6264.856289863586},
  'task': '/sryu_TaskChain_Data_wq_testt_160204_061048_5587/RECOCOSD'}
 
 class DataMap_t(unittest.TestCase):
@@ -183,6 +191,18 @@ def testConvertToArchiverFormat(self):
  for step in newData['steps']:
  if step['name'] == 'cmsRun1':
  runInfo = step['output'][0]['runs'][0]
+ subStruct = step.get('WMCMSSWSubprocess', {})
+ if subStruct:
+ # validate WMCMSSWSubprocess struct
+ for key in ['startTime', 'endTime', 'wallClockTime', 'userTime', 'sysTime']:
+ self.assertTrue(subStruct[key] > 0)
+
+ wmTiming = newData.get('WMTiming', {})
+ if wmTiming:
+ # validate WMTiming struct
+ for key in ['WMJobStart', 'WMJobEnd', 'WMTotalWallClockTime']:
+ self.assertTrue(wmTiming[key] > 0)
+
  # we no longer ship the lumis and eventsPerLumi lists to WMArchive. Hard-wired to []
  self.assertEqual(runInfo['lumis'], [])
  self.assertEqual(runInfo['eventsPerLumi'], [])

diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ErrorCodeFail.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ErrorCodeFail.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_MonteCarlo_reqmgr1_160430_052119_387/Production",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -61,6 +64,11 @@
  }
  },
  "cmsRun1": {
+ "WMCMSSWSubprocess": {"endTime": 1692718964.7409143,
+ "startTime": 1692712699.8846245,
+ "sysTime": 94.256681,
+ "userTime": 6053.7735170000005,
+ "wallClockTime": 6264.856289863586},
  "status": 8001,
  "logs": {
  },

diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/FailedByAgent.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/FailedByAgent.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_TaskChain_Task_Multicore_reqmgr1_160430_020832_2190/HLTD/HLTDMergeRAWoutput/RECODreHLT",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -55,4 +58,4 @@
  "jobid": 1002,
  "type": "fwjr",
  "jobtype": "Processing"
-}
+}
diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/HarvestSuccessFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/HarvestSuccessFwjr.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_DQMHarvesting_Sryu_reqmgr2_160318_050142_4405/EndOfRunDQMHarvest",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -61,6 +64,11 @@
  }
  },
  "cmsRun1": {
+ "WMCMSSWSubprocess": {"endTime": 1692718964.7409143,
+ "startTime": 1692712699.8846245,
+ "sysTime": 94.256681,
+ "userTime": 6053.7735170000005,
+ "wallClockTime": 6264.856289863586},
  "status": 0,
  "logs": {
  },
@@ -467,4 +475,4 @@
  "jobid": 827,
  "type": "fwjr",
  "jobtype": "Harvesting"
-}
+}
diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/LogCollectFailedFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/LogCollectFailedFwjr.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_MonteCarlo_PhEDEx_Sryu_reqmgr2_160318_050123_7744/Production/ProductionMergeLHEoutput/ProductionLHEoutputMergeLogCollect",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [

diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/LogCollectSuccessFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/LogCollectSuccessFwjr.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_DQMHarvesting_Sryu_reqmgr2_160318_050142_4405/EndOfRunDQMHarvest/EndOfRunDQMHarvestLogCollect",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [

diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/MergeFailedFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/MergeFailedFwjr.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_ReRecoSkim_Sryu_reqmgr2_160318_050217_7302/DataProcessing/DataProcessingMergeRECOoutput",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -55,4 +58,4 @@
  "jobid": 3427,
  "type": "fwjr",
  "jobtype": "Merge"
-}
+}
diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/MergeSuccessFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/MergeSuccessFwjr.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_MonteCarlo_eff_Sryu_reqmgr2_160317_161133_1935/Production/ProductionMergeRAWSIMoutput",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -61,6 +64,11 @@
  }
  },
  "cmsRun1": {
+ "WMCMSSWSubprocess": {"endTime": 1692718964.7409143,
+ "startTime": 1692712699.8846245,
+ "sysTime": 94.256681,
+ "userTime": 6053.7735170000005,
+ "wallClockTime": 6264.856289863586},
  "status": 0,
  "logs": {
  },

diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/NoJobReportFail.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/NoJobReportFail.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_TaskChain_Multicore_reqmgr1_160430_052131_7339/HLTD",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -55,4 +58,4 @@
  "jobid": 2189,
  "type": "fwjr",
  "jobtype": "Processing"
-}
+}
diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProcessingFailedFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProcessingFailedFwjr.json
@@ -6,12 +6,20 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_ReDigi_3steps_Sryu_reqmgr2_160318_050052_982/StepOneProc/StepOneProcMergeRAWSIMoutput/StepTwoProc/StepTwoProcMergeAODSIMoutput/StepThreeProc",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
  ],
  "steps": {
  "cmsRun1": {
+ "WMCMSSWSubprocess": {"endTime": 1692718964.7409143,
+ "startTime": 1692712699.8846245,
+ "sysTime": 94.256681,
+ "userTime": 6053.7735170000005,
+ "wallClockTime": 6264.856289863586},
  "status": "Failed",
  "logs": {
  },

diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProcessingPerformanceFailed.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProcessingPerformanceFailed.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_TaskChain_Task_Multicore_reqmgr1_160430_020832_2190/HLTD/HLTDMergeRAWoutput/RECODreHLT",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -49,7 +52,12 @@
  }
  },
  "cmsRun1": {
- "status": 1,
+ "WMCMSSWSubprocess": {"endTime": 1692718964.7409143,
+ "startTime": 1692712699.8846245,
+ "sysTime": 94.256681,
+ "userTime": 6053.7735170000005,
+ "wallClockTime": 6264.856289863586},
+ "status": 1,
  "logs": {
  },
  "stop": null,
@@ -333,4 +341,4 @@
  "jobid": 482,
  "type": "fwjr",
  "jobtype": "Processing"
-}
+}
diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProcessingSuccessFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProcessingSuccessFwjr.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_ReDigi_3steps_Sryu_reqmgr2_160318_050052_982/StepOneProc",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -61,6 +64,11 @@
  }
  },
  "cmsRun1": {
+ "WMCMSSWSubprocess": {"endTime": 1692718964.7409143,
+ "startTime": 1692712699.8846245,
+ "sysTime": 94.256681,
+ "userTime": 6053.7735170000005,
+ "wallClockTime": 6264.856289863586},
  "status": 0,
  "logs": {
  },
@@ -280,4 +288,4 @@
  "jobid": 1004,
  "type": "fwjr",
  "jobtype": "Processing"
-}
+}
diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProductionFailedFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProductionFailedFwjr.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_MonteCarlo_Sryu_reqmgr2_160318_050144_6584/Production",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -61,6 +64,11 @@
  }
  },
  "cmsRun1": {
+ "WMCMSSWSubprocess": {"endTime": 1692718964.7409143,
+ "startTime": 1692712699.8846245,
+ "sysTime": 94.256681,
+ "userTime": 6053.7735170000005,
+ "wallClockTime": 6264.856289863586},
  "status": 8001,
  "logs": {
  },

diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProductionSuccessFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/ProductionSuccessFwjr.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_MonteCarlo_eff_Sryu_reqmgr2_160317_161133_1935/Production",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -61,6 +64,11 @@
  }
  },
  "cmsRun1": {
+ "WMCMSSWSubprocess": {"endTime": 1692718964.7409143,
+ "startTime": 1692712699.8846245,
+ "sysTime": 94.256681,
+ "userTime": 6053.7735170000005,
+ "wallClockTime": 6264.856289863586},
  "status": 0,
  "logs": {
  },

diff --git a/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/SkimSuccessFwjr.json b/test/python/WMCore_t/Services_t/WMArchive_t/FWJRSamples/SkimSuccessFwjr.json
@@ -6,6 +6,9 @@
  "retrycount": 0,
  "fwjr": {
  "task": "/sryu_ReRecoSkim_Sryu_reqmgr2_160318_050217_7302/DataProcessing/DataProcessingMergeRECOoutput/skim_2012A_BTag",
+ "WMTiming": {"WMJobStart": 1692712699.8846245,
+ "WMJobEnd": 1692718964.7409143,
+ "WMTotalWallClockTime": 6264.856289863586},
  "skippedFiles": [
  ],
  "fallbackFiles": [
@@ -61,6 +64,11 @@
  }
  },
  "cmsRun1": {
+ "WMCMSSWSubprocess": {"endTime": 1692718964.7409143,
+ "startTime": 1692712699.8846245,
+ "sysTime": 94.256681,
+ "userTime": 6053.7735170000005,
+ "wallClockTime": 6264.856289863586},
  "status": 0,
  "logs": {
  },
@@ -440,4 +448,4 @@
  "jobid": 4469,
  "type": "fwjr",
  "jobtype": "Skim"
-}
+}