hltTimingSummaryMacroFAQ

What is a good CPU performance that can help my proposed trigger get approved?

First, your proposed path should not add a significant amount of time to the whole menu. This can be shown by comparing the totalTime plot with and without your new path. The new hltTimingSummaryMacro can help you do the comparison more quickly and easily. See How to exclude path(s) from timing.

Second, your proposed path should not add very long tail to the timing distribution. This can be checked by looking at the overflows in the totalTime plot. The new hltTimingSummaryMacro can help you check which paths contribute to the overflow. See Which paths contribute to the overflow events in total time distribution?.

Third, you can also show some additional timing plots (e.g. average path time, average module running time for modules in the path).

Fourth, the timing study is supposed to be performed on a MinBias sample which is skimmed on the L1 seed of the path. This way there will be enough statistics to get an accurate estimate of the performance. It should also be done with a reasonably high instantaneous luminosity run, since performance often scales with luminosity.

What is hltTimingSummary macro?

See hltTimingSummaryMacroIntro

How can I run the hltTimingSummary macro?

See HLTCpuTimingInstructions

.pdf file is finally produced by the macro! But ... what are the important plots out of the billion pages?

The two most important plots produced by the macro are the "Total time for all modules per event" and "average time per path." For a brief summary of all outputs by hltTimingSummary macro, see Summary_of_the_pdf_output.

An example of the macro output from Run135735 is used for explanation. The actual plots may change due to L1 composition of data or monte carlo simulation events.

total time distribution

The "Total time for all modules per event" plot, the first plot in the pdf output file, shows the distribution of the event total time in a run. A total time of an event is the sum of the time by the executed modules.

totalTime.pdf

An usual total time plot, like the example shown, can be divided into four regions:

1. First peak (from 0 to 27 msec)

The first peak consists of events where the signals fail very quickly after it enters the HLT. These events correspond to events that only execute some fast and basic modules, like checking trigger type of the L1 seeds and checking if there is L1 seed. When an event has an undesired trigger type or it has no information from the L1, the event fails immediately with a very short total time. These fast events contribute to the first peaks.

2. Second peak (from 27 to 46 msec)

The second peak consists of events where signals are further analyzed by executing the related modules. Once the HLT recognizes the L1 seeds, the signals then triggers modules to unpack the detector information. Depending on the features of the signals, different modules are called to execute the HLT trigger path, which aims at identifying the corresponding particles/physics.

For example, to ensure an electron candidate is an electron, one has to first unpack the information in the surrounding ECAL.

3. Tail (from 46 to 200 msec)

However, some signals require longer time for analysis; these long events contribute to the tail. For example, while regional unpacking is possible for certain objects (like electrons), other candidates may be identified by unpacking information from several regions. Jet candidates, for instance, need to unpack both ECAL and HCAL information because jets cover both regions in the detector.

4. Overflow (from 200 msec to infinity)

In order to show a clear distribution on the total time plot, the macro selects the best time ranges to plot. Events that take very long time falls into the overflow, which is shown in the legend. Note that the macro takes into account the overflow cases when calculating the mean total time.

average time per path plot

The "average time per path" plot shows average path time for each path in a run. Average path time of a path is the sum of time taken by the path in all events divided by the total number of events. The plot shows, in average, which paths take the longest time in an event.

avePathTimeAll.pdf

For example, in the given run with 139 paths, HLTriggerFirstPath has the longest average path time of about 8.8 msec in the run. Note that, because this example is a MinBias dataset, the paths with zero path time are the paths related to the Calibration events and other events like Randoms or DTErrors. These events are not accepted at the beginning of the HLT analysis.

How to obtain a list of the overflow events in total time distribution in my timing study?

One can obtain a list of run and event numbers of the overflow using the option -l. For a full description of the macro's available options, click here.

For example, in the given run, the events with total time exceeding 200 msec falls into the overflow category. One can add the option:

-l 200

The run and event numbers of overflow events are printed in the output summary file in a python format, which can be copied and pasted directly to do CMSSW job:

The following 43 events took longer than 200 msec to run: 
(formatted for usage within the PoolSource module,i.e, Run:Event)

eventsToProcess = cms.untracked.VEventRange(
'135735:22055809',
'135735:22112642',
'135735:22131036',
...
)

Which paths contribute to....

the overflow events in total time distribution?

One can use the option -q to plot the average path time for all the overflow events. For a full description of the macro's available options, click here.

For example, in the given run, the events with total time exceeding 200 msec falls into the overflow category. One can add the option:

-q 200,99999

Then, the macro produce

avePathTimeOver.pdf

From the plot, one can immediately identify the time-consuming path, HLT_Photon15_TrackIso_L1R, which takes about 68 msec for each overflow event in average.

the different peaks in total time distribution?

-q option can also take multiple time ranges to plot the average path time for different selection of events. For example:

-q 0,27A27,46A46,200A200,99999 will produce four "average time per path" plots that show the average path time of the events in the four regions. See Attachment-twikiExample.pdf

How to exclude path(s) from timing results?

There are two ways of doing it. Method A excludes the timing of that particular path in the hltTimingSummary marco, while method B re-runs the measurement without considering the particular path. Both ways are supposed to give the exact same result, but it turns out that a timing discrepancy exists while re-running the measurement.

Method A - Skipping myPath from timing calculation (faster than method B)

One can use -x option to exclude a particular path from timing results. For a full description of the macro's available options, click here.

For example:

-x myPath

Or, one can use -x to exclude a list of paths in a txt file. For example:

-x skipPaths.txt

where skipPaths.txt is:

myPath1
myPath2
myPath3

Method B - Re-running the measurement

1. Open the configuration file, offline_data.py, and comment out the unwanted path, myPath

process.Path1 = cms.Path(process.HLTBeginSequenceBPTX + process.hltLevel1Activity)
process.Path2 = cms.Path(process.HLTDoLocalPixelSequence + process.hltPixelActivityFilter + process.HLTEndSequence )
#process.myPath = cms.Path( process.HLTBeginSequence + process.hltDTTFUnpacker + process.hltDTActivityFilter + process.HLTEndSequence )
process.Path3 = cms.Path(process.hltDTActivityFilterTuned + process.HLTEndSequence )
...

2. Comment out the prescale of myPath (if any)

process.PrescaleService = cms.Service( "PrescaleService",
    lvl1DefaultLabel = cms.untracked.string( "0" ),
    lvl1Labels = cms.vstring( '0' ),
    prescaleTable = cms.VPSet( 
      cms.PSet(  pathName = cms.string( "Path1" ),
        prescales = cms.vuint32( 100 )
      ),
      cms.PSet(  pathName = cms.string( "Path2" ),
        prescales = cms.vuint32( 100 )
      ),
#    cms.PSet(  pathName = cms.string( "myPath" ),
#     prescales = cms.vuint32( 40 )
#    ),
      cms.PSet(  pathName = cms.string( "Path3" ),
        prescales = cms.vuint32( 100 )
      ),
      ...
  )

3. cmsRun the configuration file to produce HLT.root

cmsRun offline_data.py >&! full.log

4. Use hltTimingSummary macro to plot and analyze the timing of the run

Available options in the hltTimingSummary macro

There are two version of hltTimindSummary macro. Version 1 is the default version from release, while version 2 is an unofficial version with additional options.

Release version of hltTimingSummary macro

One can execute the release version of hltTimingSummary macro using the executable $CMSSW_RELEASE_BASE/test/$SCRAM_ARCH/hltTimingSummary. For the available options, see Using the macro.

Unofficial version of hltTimingSummary macro

One can update the unofficial version of hltTimingSummary macro:

1. Check out the latest version here.

2. Copy it to ~/CMSSW_X_X_X/src/DataFormats/HLTReco/test/

3. Compile it by commanding scramv1 build

4. Execute the updated version of hltTimingSummary macro using the executable $CMSSW_BASE/test/$SCRAM_ARCH/hltTimingSummary.

This version is fully tested and include the following additional options:

  -p [ --pdfLevel ] arg Set the level of pdf verbosity: 0 (none), 1 (summary
                        plots only), 2 (default), 3 (full - default + Path rejection factor 
                        + Path success rate + Path vs Path success rate 
                        + Fraction of single path + Module rejection factor)
  -y [--logY]     Plot event histograms with y-axis in log scale
  -l [--timelimit] arg     Print event & run numbers of events where 
                            total time exceeds user-specified limit (in msec) listed in summary file
  -a [--pathlimit] arg     Print event & run numbers of events where
                            any path time exceeds user-specified limit (in msec) listed in summary file
  -m [--modulelimit] arg     Print event & run numbers of events where 
                            any module time exceeds user-specified limit (in msec) listed in summary file
  -x [--excludePath] arg     Exclude the users' given path from timing calculation
  -g [--modPrint] arg     Print event and run numbers of events where 
                            the user's input modules exceed the modulelimit in summary file
  -q [--timeSpecific] arg     Plot average path time of events where 
                            total time is within user-specified ranges (in msec) and 
                            stacked path time plots with different color according to the time ranges

Examples:

"hltTimingSummary -i in.root -o out -m 10 -g myModule -x myPath" inputs in.root, outputs out.root,
                         out-bookmark.txt, out-summary.txt and out.pdf.
                         Also prints out Run and Event numbers of events with at least one module
                         run more than 10 msec in out-summary.txt, and prints out the Run and 
                         Event numbers of events with the module, myModule, runs more than 10 msec, and 
                         exclude the path, myPath, from timing calculation.
"hltTimingSummary -i in.root -o out -q 30,100A500,99999" inputs in.root, outputs out.root,
                         out-bookmark.txt, out-summary.txt and out.pdf.
                         Also plots 2 average path time plots: 
                         1) for events with total time ranged from 30 to 100 msec,
                         2) for events with total time ranged from 500 msec to infinity; and
                         plots stacked histograms for path time plots for each path with
                         colors corresponding to the colors in the average path time plots.

-- ElimCheung - 05-Jul-2010

  • totalTime.pdf: Example of "Total time for all modules per event" plot

Topic attachments
I Attachment History Action Size Date Who Comment
PDFpdf avePathTimeAll.pdf r1 manage 18.4 K 2010-07-05 - 21:53 ElimCheung Example of ""average time per path" plot for All events
PDFpdf avePathTimeOver.pdf r1 manage 18.4 K 2010-07-05 - 21:54 ElimCheung Example of "average time per path" plot for overflow events
PDFpdf totalTime.pdf r1 manage 14.9 K 2010-07-05 - 21:52 ElimCheung Example of "Total time for all modules per event" plot
PDFpdf twikiExample-bm.pdf r1 manage 13797.5 K 2010-07-05 - 21:55 ElimCheung Example of hltTimingSummary output
Edit | Attach | Watch | Print version | History: r15 < r14 < r13 < r12 < r11 | Backlinks | Raw View | WYSIWYG | More topic actions
Topic revision: r15 - 2010-08-31 - EdgarCarrera
 
    • Cern Search Icon Cern Search
    • TWiki Search Icon TWiki Search
    • Google Search Icon Google Search

    Sandbox All webs login

This site is powered by the TWiki collaboration platform Powered by PerlCopyright & 2008-2020 by the contributing authors. All material on this collaboration platform is the property of the contributing authors.
or Ideas, requests, problems regarding TWiki? use Discourse or Send feedback