Debugging
Sometimes your options files don’t do what you expect them to. Analysing the output is a good first step, but there are a few other techniques that can be useful.
This page will continue to use the two options files made in the Running Moore tutorial.
Dry runs
When the problem is with the configuration, you often don’t need to actually
run the application itself, just the configuration step. You can do this with
the -n
flag that gaudirun.py
supports:
./Moore/run gaudirun.py -n input_data.py hlt1_example.py
This will stop just before running the application, so will also generate the Data and control flow graphs described above.
An easy way to see DEBUG level messages from Python is to pass --debug
to
gaudirun.py
:
./Moore/run gaudirun.py -n --debug input_data.py hlt1_example.py
Dumping the configuration
When executed together, a set of options files define the configuration of a
number of Gaudi Configurable objects, and this configuration can be dumped to a
file. We can create a dump with our example options using the --all-opts
and --output
flags to gaudirun.py
(combined with the dry runs
technique, as we don’t need the application itself to run):
./Moore/run gaudirun.py -n --all-opts --output default_example.opts.py input_data.py hlt1_example.py
Have a poke around the created file, default_example.opts.py
, and see what
it contains. This can be very useful by itself.
Inspecting differences
By dumping the configuration of two runs of some options files, we can
compare them. The diffopts.py
script included in Moore let’s you _see_ how
a change to your options file affects the configuration of the application.
As an example, create a new options file called input_data_digi.py
that
loads a different key from the test file database:
from Moore import options
options.evt_max = 100
options.set_input_and_conds_from_testfiledb("MiniBrunel_2018_MinBias_FTv4_DIGI")
This loads files with the .digi
extension, rather than the .mdf
extension we’ve been using.
Create an options file dump as before, but substitute input_data.py
with
the new file, and give a different name to the --output
argument of
gaudirun.py
, say digi_example.opts.py
.
Finally, run the diff script:
./Moore/run diffopts.py default_example.opts.py digi_example.opts.py
This prints out the diff in the same style the git diff
command does:
diff --git default_example.opts.py/EventSelector digi_example.opts.py/EventSelector
index 4e66aef..f59a649 100644
--- default_example.opts.py/EventSelector
+++ digi_example.opts.py/EventSelector
@@ -8,16 +8,12 @@
"EvtMax": 2147483647
"FirstEvent": 0
"Input": [
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'",
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'",
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'",
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'",
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'",
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'",
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'",
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'",
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'",
- "DATAFILE='mdf:root://eoslhcb.cern.ch//eos/lhcb/grid/prod/lhcb/swtest/lhcb/swtest/MiniBrunel/00067189.mdf' SVC='LHCb::MDFSelector' OPT='READ' IgnoreChecksum='YES'"
+ "DATAFILE='root://eoslhcb.cern.ch//eos/lhcb/wg/SciFi/Simulation/MinBiasRawBankv5/00067189_1.digi.digi' SVC='Gaudi::RootEvtSelector' OPT='READ' IgnoreChecksum='YES'",
+ "DATAFILE='root://eoslhcb.cern.ch//eos/lhcb/wg/SciFi/Simulation/MinBiasRawBankv5/00067189_2.digi.digi' SVC='Gaudi::RootEvtSelector' OPT='READ' IgnoreChecksum='YES'",
+ "DATAFILE='root://eoslhcb.cern.ch//eos/lhcb/wg/SciFi/Simulation/MinBiasRawBankv5/00067189_3.digi.digi' SVC='Gaudi::RootEvtSelector' OPT='READ' IgnoreChecksum='YES'",
+ "DATAFILE='root://eoslhcb.cern.ch//eos/lhcb/wg/SciFi/Simulation/MinBiasRawBankv5/00067189_4.digi.digi' SVC='Gaudi::RootEvtSelector' OPT='READ' IgnoreChecksum='YES'",
+ "DATAFILE='root://eoslhcb.cern.ch//eos/lhcb/wg/SciFi/Simulation/MinBiasRawBankv5/00067189_5.digi.digi' SVC='Gaudi::RootEvtSelector' OPT='READ' IgnoreChecksum='YES'",
+ "DATAFILE='root://eoslhcb.cern.ch//eos/lhcb/wg/SciFi/Simulation/MinBiasRawBankv5/00067189_6.digi.digi' SVC='Gaudi::RootEvtSelector' OPT='READ' IgnoreChecksum='YES'"
]
"OutputLevel": 0
"PrintFreq": 10000
You can see here that the only difference is that the input file paths and
xml
catalogue are different. So we can already deduce many useful things
that might help ourdebugging, such as the fact that the database tags are the
same between the two sets of options (otherwise we would see different values
in the diff).
Profiling
When your options files are slow, it can be useful to profile them. PyConf ships with an options file that will set up a profiler for you. Combined with dry runs, this allows you to quickly iterate on a slow-down:
./Moore/run gaudirun.py -n '$PYCONFROOT/options/profile_config.py' input_data.py hlt1_example.py
This prints out a timing table like this:
Elapsed CPU time 4.8
4380348 function calls (4359554 primitive calls) in 6.796 seconds
Ordered by: cumulative time
List reduced from 1639 to 164 due to restriction <0.1>
ncalls tottime percall cumtime percall filename:lineno(function)
2 0.000 0.000 6.777 3.388 /home/apearce/stack/Gaudi/InstallArea/x86_64-centos7-gcc8-dbg/python/GaudiKernel/ProcessJobOptions.py:481(importOptions)
2 0.000 0.000 6.776 3.388 /home/apearce/stack/Gaudi/InstallArea/x86_64-centos7-gcc8-dbg/python/GaudiKernel/ProcessJobOptions.py:457(_import_python)
1 0.000 0.000 4.795 4.795 /home/apearce/stack/hlt1_example.py:1(<module>)
1 0.000 0.000 4.612 4.612 /home/apearce/stack/Moore/Hlt/Moore/python/Moore/config.py:125(run_moore)
1 0.000 0.000 3.434 3.434 /home/apearce/stack/Moore/PyConf/python/PyConf/application.py:430(configure)
...
If certain functions are taking a lot of time, you’ll be able to see them here.
The debug
helper
The configuration framework ‘behind’ Moore is called PyConf, whose Tonic
component provides the @configurable
helper you’ll see decorating various functions.
If you want to get some more feedback about what Tonic is doing, you can use
the debug
context manager:
from PyConf.tonic import debug
with debug():
# Do stuff
Inside the debug
context, the verbosity of the logging from Tonic will be
increased.
Gaudi Auditors
The Gaudi framework has a number of Auditors that provide useful optional debugging capabilities. They span from basic ones, like the ‘NameAuditor’ that simply prints a message whenever an algorithm is entered or exited, to more complicated ones like support for using the Google or Intel profilers. For more details on all that are available see the Gaudi doxygen documentation.
The configuration framework has support for enabling any number of these, by passing their names to the application configuration:
option.auditors = ['NameAuditor']