improve logging of addOnTests

[missirol]

PR description:

This PR is alternative to #36423.

The issue is that different "addon" tests can produce log files with the same basename. When one of these tests fails, the cmsbuild bot has trouble identifying which test failed (see #40011 (comment) for an example).

The (potential) fix in #36423 is minimal but fragile. This PR is more invasive, and changes the names of the addOnTests logs in order to make them unique by construction.

With this PR, a "addon" test XYZ with N steps creates log files named XYZ/step{1,..,N}.log. In addition, a text file named cmdLog with the list of steps is added to every addon sub-directory XYZ. Lines in the main log file of the addOnTests have the following format

[hlt_data_PRef:1] cmsDriver.py RelVal -s L1REPACK:Full --data --scenario=pp -n 10 --conditions auto:run3_hlt_PRef --relval 9000,50 --datatier "RAW" --customise=HLTrigger/Configuration/CustomConfigs.L1T --era Run3 --eventcontent RAW --fileout file:RelVal_Raw_PRef_DATA.root --filein root://eoscms.cern.ch//eos/cms/store/group/dpg_trigger/comm_trigger/TriggerStudiesGroup/STORM/RAW/Run2022B_HLTPhysics0_run355558/cd851cf4-0fca-4d76-b80e-1d33e1371929.root : PASSED - elapsed time: 26 sec (ended on Tue Nov  8 23:34:13 2022) - exit: 0

[hlt_data_PRef:2] cmsRun /work/missiroli_m/test/tsg/storm/devel_addOnTestsLogFileName/CMSSW_12_6_0_pre4/src/HLTrigger/Configuration/test/OnLine_HLT_PRef.py realData=True globalTag=@ inputFiles=@ : PASSED - elapsed time: 56 sec (ended on Tue Nov  8 23:35:10 2022) - exit: 0

[hlt_data_PRef:3] cmsDriver.py RelVal -s HLT:PRef,RAW2DIGI,L1Reco,RECO --data --scenario=pp -n 10 --conditions auto:run3_data_PRef --relval 9000,50 --datatier "RAW-HLT-RECO" --eventcontent FEVTDEBUGHLT --customise=HLTrigger/Configuration/CustomConfigs.L1THLT --customise=HLTrigger/Configuration/CustomConfigs.HLTRECO --customise=HLTrigger/Configuration/CustomConfigs.customiseGlobalTagForOnlineBeamSpot --era Run3 --processName=HLTRECO --filein file:RelVal_Raw_PRef_DATA.root --fileout file:RelVal_Raw_PRef_DATA_HLT_RECO.root : PASSED - elapsed time: 84 sec (ended on Tue Nov  8 23:36:35 2022) - exit: 0

The first bit, i.e. [test:N], is added for clarity, and to allow the bot to find the correct log file without ambiguities.

The way elapsed time is reported for every given addon test is also updated.

This PR requires cms-sw/cms-bot#1879.

PR validation:

addOnTests.py passed.

If this PR is a backport, please specify the original PR and why you need to backport that PR. If this PR will be backported, please specify to which release cycle the backport is meant for:

N/A

[cmsbuild]

+code-checks

Logs: https://cmssdt.cern.ch/SDT/code-checks/cms-sw-PR-40018/32972

• This PR adds an extra 12KB to repository

• There are other open Pull requests which might conflict with changes you have proposed:

  • File Utilities/ReleaseScripts/scripts/addOnTests.py modified in PR(s): increase max length of addOnTests log-file names #36423

[cmsbuild]

A new Pull Request was created by @missirol (Marino Missiroli) for master.

It involves the following packages:

• Utilities/ReleaseScripts (core)

@cmsbuild, @smuzaffar, @Dr15Jones, @makortel can you please review it and eventually sign? Thanks.
@wddgit this is something you requested to watch as well.
@perrotta, @dpiparo, @rappoccio you are the release manager for this.

cms-bot commands are listed here

[missirol]

test parameters:

• pull_requests = cope with improved logging of addOnTests cms-bot#1879

[missirol]

please test with #40011

#40011 will make this fail. If this PR works, the bot should point to the failed addon test.

[cmsbuild]

-1

Failed Tests: AddOn
Summary: https://cmssdt.cern.ch/SDT/jenkins-artifacts/pull-request-integration/PR-bb03f7/28895/summary.html
COMMIT: cf41268
CMSSW: CMSSW_12_6_X_2022-11-08-2000/el8_amd64_gcc10
User test area: For local testing, you can use /cvmfs/cms-ci.cern.ch/week0/cms-sw/cmssw/40018/28895/install.sh to create a dev area with all the needed externals and cmssw changes.

AddOn Tests

• unknown[hlt_data_HIon:1] cmsRun /cvmfs/cms-ib.cern.ch/sw/x86_64/nweek-02758/el8_amd64_gcc10/cms/cmssw-patch/CMSSW_12_6_X_2022-11-08-2000/src/HLTrigger/Configuration/test/OnLine_HLT_HIon.py realData=True globalTag=@ inputFiles=@ : FAILED - elapsed time: 231 sec (ended on Wed Nov 9 03:15:23 2022) - exit: 16640

Comparison Summary

Summary:

• No significant changes to the logs found
• Reco comparison results: 10 differences found in the comparisons
• DQMHistoTests: Total files compared: 48
• DQMHistoTests: Total histograms compared: 3416402
• DQMHistoTests: Total failures: 12
• DQMHistoTests: Total nulls: 0
• DQMHistoTests: Total successes: 3416368
• DQMHistoTests: Total skipped: 22
• DQMHistoTests: Total Missing objects: 0
• DQMHistoSizes: Histogram memory added: 0.0 KiB( 47 files compared)
• Checked 206 log files, 48 edm output root files, 48 DQM output files
• TriggerResults: no differences found

[missirol]

test parameters:

• pull_requests = cope with improved logging of addOnTests cms-bot#1879, Remove MVASelector tags for tracking in data GTs + re-snapshot frozen GT #40011

[missirol]

please test

It didn't really work yet (see #40018 (comment)); my only guess is that #40018 (comment) overwrote #40018 (comment) (instead of combining them, which was my naive expectation). Let me retry.

[cmsbuild]

-1

Failed Tests: AddOn
Summary: https://cmssdt.cern.ch/SDT/jenkins-artifacts/pull-request-integration/PR-bb03f7/28898/summary.html
COMMIT: cf41268
CMSSW: CMSSW_12_6_X_2022-11-08-2000/el8_amd64_gcc10
User test area: For local testing, you can use /cvmfs/cms-ci.cern.ch/week0/cms-sw/cmssw/40018/28898/install.sh to create a dev area with all the needed externals and cmssw changes.

AddOn Tests

• hlt_data_HIon

----- Begin Fatal Exception 09-Nov-2022 08:39:54 CET-----------------------
An exception of category 'NoProxyException' occurred while
   [0] Processing  Event run: 355558 lumi: 224 event: 215118413 stream: 0
   [1] Running path 'HLT_HIDmesonPPTrackingGlobal_Dpt30_v3'
   [2] Calling method for module TrackMVAClassifierPrompt/'hltFullIter10TrackMVAClassifierPPOnAA'
Exception Message:
No data of type "GBRForest" with label "MVASelectorJetCoreRegionalStep_Phase1" in record "GBRWrapperRcd"
 Please add an ESSource or ESProducer to your job which can deliver this data.
----- End Fatal Exception -------------------------------------------------

Comparison Summary

Summary:

• No significant changes to the logs found
• Reco comparison results: 5 differences found in the comparisons
• DQMHistoTests: Total files compared: 48
• DQMHistoTests: Total histograms compared: 3416402
• DQMHistoTests: Total failures: 9
• DQMHistoTests: Total nulls: 0
• DQMHistoTests: Total successes: 3416371
• DQMHistoTests: Total skipped: 22
• DQMHistoTests: Total Missing objects: 0
• DQMHistoSizes: Histogram memory added: 0.0 KiB( 47 files compared)
• Checked 206 log files, 48 edm output root files, 48 DQM output files
• TriggerResults: no differences found

[missirol]

test parameters:

• pull_requests = cope with improved logging of addOnTests cms-bot#1879

[missirol]

please test

#40018 (comment) shows the expected output (okay, it does not say which step failed, but that was already the case before this PR, and it requires a couple more tweaks on the cms-bot side, I would postpone this refinement).

Now rerunning tests to see them pass.

[missirol]

I updated this PR to start numbering steps from 1 rather than 0; this follows what is displayed on the IB webpage [example] (i.e. step1, step2, step3):
https://github.com/cms-sw/cmssw/compare/cf4126824f49c1e91c259e9e38b166938d2ee7c9..463cc22f8ba10f80a9a4f9167803da646bbeb72c

cms-sw/cms-bot#1879 does not need to be updated for this.

cms-sw/cmssdt-web#7 contains the corresponding cmssdt update discussed in #40018 (comment).

[cmsbuild]

+code-checks

Logs: https://cmssdt.cern.ch/SDT/code-checks/cms-sw-PR-40018/33041

• This PR adds an extra 12KB to repository

• There are other open Pull requests which might conflict with changes you have proposed:

  • File Utilities/ReleaseScripts/scripts/addOnTests.py modified in PR(s): increase max length of addOnTests log-file names #36423

[cmsbuild]

Pull request #40018 was updated. @cmsbuild, @smuzaffar, @Dr15Jones, @makortel can you please check and sign again.

[missirol]

please test

[cmsbuild]

+1

Summary: https://cmssdt.cern.ch/SDT/jenkins-artifacts/pull-request-integration/PR-bb03f7/29001/summary.html
COMMIT: 463cc22
CMSSW: CMSSW_12_6_X_2022-11-14-2300/el8_amd64_gcc10
User test area: For local testing, you can use /cvmfs/cms-ci.cern.ch/week1/cms-sw/cmssw/40018/29001/install.sh to create a dev area with all the needed externals and cmssw changes.

Comparison Summary

Summary:

• No significant changes to the logs found
• Reco comparison results: 8 differences found in the comparisons
• DQMHistoTests: Total files compared: 48
• DQMHistoTests: Total histograms compared: 3417074
• DQMHistoTests: Total failures: 6
• DQMHistoTests: Total nulls: 0
• DQMHistoTests: Total successes: 3417046
• DQMHistoTests: Total skipped: 22
• DQMHistoTests: Total Missing objects: 0
• DQMHistoSizes: Histogram memory added: 0.0 KiB( 47 files compared)
• Checked 206 log files, 48 edm output root files, 48 DQM output files
• TriggerResults: no differences found

[missirol]

@makortel @smuzaffar , do you have any further comments on this PR? (Core-sw signature required)

It's not necessary for 12_6_0_pre5, but I would like to have it merged eventually (the ancillary PRs outside CMSSW are merged).

[makortel]

Looks ok to me. @smuzaffar, what do you think?

[smuzaffar]

+core
looks good, both bot and cmssdt-web PR required for this change are already merged.

[cmsbuild]

This pull request is fully signed and it will be integrated in one of the next master IBs (tests are also fine). This pull request will now be reviewed by the release team before it's merged. @perrotta, @dpiparo, @rappoccio (and backports should be raised in the release meeting by the corresponding L2)

[perrotta]

+1