ModuleManager.cpp 35.8 KB
Newer Older
1
2
3
4
5
6
7
8
/** @file
 *  @brief Interface to the core framework
 *  @copyright Copyright (c) 2017 CERN and the Corryvreckan authors.
 * This software is distributed under the terms of the MIT License, copied verbatim in the file "LICENSE.md".
 * In applying this license, CERN does not waive the privileges and immunities granted to it by virtue of its status as an
 * Intergovernmental Organization or submit itself to any jurisdiction.
 */

9
// ROOT include files
10
11
12
13
#include <Math/DisplacementVector2D.h>
#include <Math/Vector2D.h>
#include <Math/Vector3D.h>
#include <TFile.h>
14
#include <TSystem.h>
15
16

// Local include files
17
18
19
#include "ModuleManager.hpp"
#include "core/utils/log.h"
#include "exceptions.h"
20

21
#include <chrono>
22
23
#include <dlfcn.h>
#include <fstream>
24
#include <iomanip>
25

26
27
#define CORRYVRECKAN_MODULE_PREFIX "libCorryvreckanModule"
#define CORRYVRECKAN_GENERATOR_FUNCTION "corryvreckan_module_generator"
28
29
#define CORRYVRECKAN_GLOBAL_FUNCTION "corryvreckan_module_is_global"
#define CORRYVRECKAN_DUT_FUNCTION "corryvreckan_module_is_dut"
30
#define CORRYVRECKAN_TYPE_FUNCTION "corryvreckan_detector_types"
31

32
33
using namespace corryvreckan;

34
// Default constructor
35
36
37
ModuleManager::ModuleManager(std::string config_file_name,
                             const std::vector<std::string>& module_options,
                             const std::vector<std::string>& detector_options)
Simon Spannagel's avatar
Simon Spannagel committed
38
    : m_reference(nullptr), m_terminate(false) {
39

Simon Spannagel's avatar
Simon Spannagel committed
40
41
42
43
44
    LOG(TRACE) << "Loading Corryvreckan";

    // Put welcome message
    LOG(STATUS) << "Welcome to Corryvreckan " << CORRYVRECKAN_PROJECT_VERSION;

Simon Spannagel's avatar
Simon Spannagel committed
45
    // Load the global configuration
46
47
48
    conf_manager_ = std::make_unique<corryvreckan::ConfigManager>(std::move(config_file_name),
                                                                  std::initializer_list<std::string>({"Corryvreckan", ""}),
                                                                  std::initializer_list<std::string>({"Ignore"}));
49

50
51
    // Load and apply the provided module options
    conf_manager_->loadModuleOptions(module_options);
52

53
54
    // Load and apply the provided detector options
    conf_manager_->loadDetectorOptions(detector_options);
55

Simon Spannagel's avatar
Simon Spannagel committed
56
    // Fetch the global configuration
57
    Configuration& global_config = conf_manager_->getGlobalConfiguration();
Simon Spannagel's avatar
Simon Spannagel committed
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97

    // Set the log level from config if not specified earlier
    std::string log_level_string;
    if(Log::getReportingLevel() == LogLevel::NONE) {
        log_level_string = global_config.get<std::string>("log_level", "INFO");
        std::transform(log_level_string.begin(), log_level_string.end(), log_level_string.begin(), ::toupper);
        try {
            LogLevel log_level = Log::getLevelFromString(log_level_string);
            Log::setReportingLevel(log_level);
        } catch(std::invalid_argument& e) {
            LOG(ERROR) << "Log level \"" << log_level_string
                       << "\" specified in the configuration is invalid, defaulting to INFO instead";
            Log::setReportingLevel(LogLevel::INFO);
        }
    } else {
        log_level_string = Log::getStringFromLevel(Log::getReportingLevel());
    }

    // Set the log format from config
    std::string log_format_string = global_config.get<std::string>("log_format", "DEFAULT");
    std::transform(log_format_string.begin(), log_format_string.end(), log_format_string.begin(), ::toupper);
    try {
        LogFormat log_format = Log::getFormatFromString(log_format_string);
        Log::setFormat(log_format);
    } catch(std::invalid_argument& e) {
        LOG(ERROR) << "Log format \"" << log_format_string
                   << "\" specified in the configuration is invalid, using DEFAULT instead";
        Log::setFormat(LogFormat::DEFAULT);
    }

    // Open log file to write output to
    if(global_config.has("log_file")) {
        // NOTE: this stream should be available for the duration of the logging
        log_file_.open(global_config.getPath("log_file"), std::ios_base::out | std::ios_base::trunc);
        Log::addStream(log_file_);
    }

    // Wait for the first detailed messages until level and format are properly set
    LOG(TRACE) << "Global log level is set to " << log_level_string;
    LOG(TRACE) << "Global log format is set to " << log_format_string;
98

Simon Spannagel's avatar
Simon Spannagel committed
99
    // New clipboard for storage:
100
    m_clipboard = std::make_shared<Clipboard>();
101
102
}

103
void ModuleManager::load() {
104
105
106

    add_units();

107
    load_detectors();
108
    load_modules();
109
110
}

111
void ModuleManager::load_detectors() {
112
    Configuration& global_config = conf_manager_->getGlobalConfiguration();
113

114
    for(auto& detector_section : conf_manager_->getDetectorConfigurations()) {
115

116
        std::string name = detector_section.getName();
117

118
119
120
121
122
123
124
        // Check if we have a duplicate:
        if(std::find_if(m_detectors.begin(), m_detectors.end(), [&name](std::shared_ptr<Detector> obj) {
               return obj->name() == name;
           }) != m_detectors.end()) {
            throw InvalidValueError(
                global_config, "detectors_file", "Detector " + detector_section.getName() + " defined twice");
        }
125

126
127
        LOG_PROGRESS(STATUS, "DET_LOAD_LOOP") << "Loading detector " << name;
        auto detector = std::make_shared<Detector>(detector_section);
128

129
130
131
132
        // Check if we already found a reference plane:
        if(m_reference != nullptr && detector->isReference()) {
            throw InvalidValueError(global_config, "detectors_file", "Found more than one reference detector");
        }
133

134
135
136
        // Switch flag if we found the reference plane:
        if(detector->isReference()) {
            m_reference = detector;
137
        }
138
139
140

        // Add the new detector to the global list:
        m_detectors.push_back(detector);
141
    }
142

143
    // Check that exactly one detector is marked as reference:
Simon Spannagel's avatar
Simon Spannagel committed
144
    if(m_reference == nullptr) {
145
146
147
        throw InvalidValueError(global_config, "detectors_file", "Found no detector marked as reference");
    }

148
    LOG_PROGRESS(STATUS, "DET_LOAD_LOOP") << "Loaded " << m_detectors.size() << " detectors";
149
150

    // Finally, sort the list of detectors by z position (from lowest to highest)
151
    std::sort(m_detectors.begin(), m_detectors.end(), [](std::shared_ptr<Detector> det1, std::shared_ptr<Detector> det2) {
152
        return det1->displacement().Z() < det2->displacement().Z();
Simon Spannagel's avatar
Simon Spannagel committed
153
    });
154
}
155

156
void ModuleManager::load_modules() {
157
158
    auto& configs = conf_manager_->getModuleConfigurations();
    Configuration& global_config = conf_manager_->getGlobalConfiguration();
Simon Spannagel's avatar
Simon Spannagel committed
159
160

    // Create histogram output file
161
162
163
    global_config.setAlias("histogram_file", "histogramFile");
    std::string histogramFile = global_config.getPath("histogram_file");

164
    m_histogramFile = std::make_unique<TFile>(histogramFile.c_str(), "RECREATE");
Simon Spannagel's avatar
Simon Spannagel committed
165
    if(m_histogramFile->IsZombie()) {
166
        throw RuntimeError("Cannot create main ROOT file " + histogramFile);
Simon Spannagel's avatar
Simon Spannagel committed
167
    }
168
    m_histogramFile->cd();
Simon Spannagel's avatar
Simon Spannagel committed
169

170
    LOG(DEBUG) << "Start loading modules, have " << configs.size() << " configurations.";
Simon Spannagel's avatar
Simon Spannagel committed
171
172
    // Loop through all non-global configurations
    for(auto& config : configs) {
173
        // Load library for each module. Libraries are named (by convention + CMAKE libCorryvreckanModule Name.suffix
Simon Spannagel's avatar
Simon Spannagel committed
174
        std::string lib_name =
175
            std::string(CORRYVRECKAN_MODULE_PREFIX).append(config.getName()).append(SHARED_LIBRARY_SUFFIX);
176
        LOG_PROGRESS(STATUS, "MOD_LOAD_LOOP") << "Loading module " << config.getName();
Simon Spannagel's avatar
Simon Spannagel committed
177
178
179
180
181
182
183

        void* lib = nullptr;
        bool load_error = false;
        dlerror();
        if(loaded_libraries_.count(lib_name) == 0) {
            // If library is not loaded then try to load it first from the config
            // directories
Simon Spannagel's avatar
Simon Spannagel committed
184
185
            if(global_config.has("library_directories")) {
                std::vector<std::string> lib_paths = global_config.getPathArray("library_directories", true);
Simon Spannagel's avatar
Simon Spannagel committed
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
                for(auto& lib_path : lib_paths) {
                    std::string full_lib_path = lib_path;
                    full_lib_path += "/";
                    full_lib_path += lib_name;

                    // Check if the absolute file exists and try to load if it exists
                    std::ifstream check_file(full_lib_path);
                    if(check_file.good()) {
                        lib = dlopen(full_lib_path.c_str(), RTLD_NOW);
                        if(lib != nullptr) {
                            LOG(DEBUG) << "Found library in configuration specified directory at " << full_lib_path;
                        } else {
                            load_error = true;
                        }
                        break;
                    }
                }
            }

            // Otherwise try to load from the standard paths if not found already
            if(!load_error && lib == nullptr) {
                lib = dlopen(lib_name.c_str(), RTLD_NOW);

                if(lib != nullptr) {
                    LOG(TRACE) << "Opened library";
                    Dl_info dl_info;
                    dl_info.dli_fname = "";

                    // workaround to get the location of the library
                    int ret = dladdr(dlsym(lib, CORRYVRECKAN_GENERATOR_FUNCTION), &dl_info);
                    if(ret != 0) {
                        LOG(DEBUG) << "Found library during global search in runtime paths at " << dl_info.dli_fname;
                    } else {
                        LOG(WARNING) << "Found library during global search but could not "
                                        "deduce location, likely broken library";
                    }
                } else {
                    load_error = true;
                }
225
226
            }
        } else {
Simon Spannagel's avatar
Simon Spannagel committed
227
228
            // Otherwise just fetch it from the cache
            lib = loaded_libraries_[lib_name];
229
230
        }

Simon Spannagel's avatar
Simon Spannagel committed
231
232
233
        // If library did not load then throw exception
        if(load_error) {
            const char* lib_error = dlerror();
234

Simon Spannagel's avatar
Simon Spannagel committed
235
236
237
238
239
240
241
            // Find the name of the loaded library if it exists
            std::string lib_error_str = lib_error;
            size_t end_pos = lib_error_str.find(':');
            std::string problem_lib;
            if(end_pos != std::string::npos) {
                problem_lib = lib_error_str.substr(0, end_pos);
            }
242

Simon Spannagel's avatar
Simon Spannagel committed
243
244
245
246
247
248
249
250
251
252
            // FIXME is checking the error in this way portable?
            if(lib_error != nullptr && std::strstr(lib_error, "cannot allocate memory in static TLS block") != nullptr) {
                LOG(ERROR) << "Library could not be loaded: not enough thread local storage "
                              "available"
                           << std::endl
                           << "Try one of below workarounds:" << std::endl
                           << "- Rerun library with the environmental variable LD_PRELOAD='" << problem_lib << "'"
                           << std::endl
                           << "- Recompile the library " << problem_lib << " with tls-model=global-dynamic";
            } else if(lib_error != nullptr && std::strstr(lib_error, "cannot open shared object file") != nullptr &&
253
                      problem_lib.find(CORRYVRECKAN_MODULE_PREFIX) == std::string::npos) {
Simon Spannagel's avatar
Simon Spannagel committed
254
255
256
257
258
259
260
261
262
263
264
265
                LOG(ERROR) << "Library could not be loaded: one of its dependencies is missing" << std::endl
                           << "The name of the missing library is " << problem_lib << std::endl
                           << "Please make sure the library is properly initialized and try "
                              "again";
            } else {
                LOG(ERROR) << "Library could not be loaded: it is not available" << std::endl
                           << " - Did you enable the library during building? " << std::endl
                           << " - Did you spell the library name correctly (case-sensitive)? ";
                if(lib_error != nullptr) {
                    LOG(DEBUG) << "Detailed error: " << lib_error;
                }
            }
266

267
            throw corryvreckan::DynamicLibraryError("Error loading " + config.getName());
Simon Spannagel's avatar
Simon Spannagel committed
268
269
270
        }
        // Remember that this library was loaded
        loaded_libraries_[lib_name] = lib;
271

272
        // Check if this module is produced once, or once per detector
273
274
        void* globalFunction = dlsym(loaded_libraries_[lib_name], CORRYVRECKAN_GLOBAL_FUNCTION);
        void* dutFunction = dlsym(loaded_libraries_[lib_name], CORRYVRECKAN_DUT_FUNCTION);
275
        void* typeFunction = dlsym(loaded_libraries_[lib_name], CORRYVRECKAN_TYPE_FUNCTION);
276

277
        // If the global function was not found, throw an error
278
        if(globalFunction == nullptr || dutFunction == nullptr || typeFunction == nullptr) {
279
280
            LOG(ERROR) << "Module library is invalid or outdated: required interface function not found!";
            throw corryvreckan::DynamicLibraryError(config.getName());
281
282
        }

283
284
285
286
287
        bool global = reinterpret_cast<bool (*)()>(globalFunction)();      // NOLINT
        bool dut_only = reinterpret_cast<bool (*)()>(dutFunction)();       // NOLINT
        char* type_tokens = reinterpret_cast<char* (*)()>(typeFunction)(); // NOLINT

        std::vector<std::string> types = get_type_vector(type_tokens);
288

Simon Spannagel's avatar
Simon Spannagel committed
289
290
291
        // Add the global internal parameters to the configuration
        std::string global_dir = gSystem->pwd();
        config.set<std::string>("_global_dir", global_dir);
292

293
        // Merge the global configuration into the modules config:
294
295
        config.merge(global_config);

296
        // Create the modules from the library
297
        std::vector<std::pair<ModuleIdentifier, Module*>> mod_list;
298
        if(global) {
299
            mod_list.emplace_back(create_unique_module(loaded_libraries_[lib_name], config));
300
        } else {
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
            mod_list = create_detector_modules(loaded_libraries_[lib_name], config, dut_only, types);
        }

        // Loop through all created instantiations
        for(auto& id_mod : mod_list) {
            // FIXME: This convert the module to an unique pointer. Check that this always works and we can do this earlier
            std::unique_ptr<Module> mod(id_mod.second);
            ModuleIdentifier identifier = id_mod.first;

            // Check if the unique instantiation already exists
            auto iter = id_to_module_.find(identifier);
            if(iter != id_to_module_.end()) {
                // Unique name exists, check if its needs to be replaced
                if(identifier.getPriority() < iter->first.getPriority()) {
                    // Priority of new instance is higher, replace the instance
                    LOG(TRACE) << "Replacing model instance " << iter->first.getUniqueName()
                               << " with instance with higher priority.";

                    module_execution_time_.erase(iter->second->get());
                    iter->second = m_modules.erase(iter->second);
                    iter = id_to_module_.erase(iter);
                } else {
                    // Priority is equal, raise an error
                    if(identifier.getPriority() == iter->first.getPriority()) {
                        throw AmbiguousInstantiationError(config.getName());
                    }
                    // Priority is lower, do not add this module to the run list
                    continue;
                }
330
            }
331
332
333
334
335
336
337
338

            // Save the identifier in the module
            mod->set_identifier(identifier);
            mod->setReference(m_reference);

            // Add the new module to the run list
            m_modules.emplace_back(std::move(mod));
            id_to_module_[identifier] = --m_modules.end();
339
        }
Simon Spannagel's avatar
Simon Spannagel committed
340
    }
341

342
    LOG_PROGRESS(STATUS, "MOD_LOAD_LOOP") << "Loaded " << m_modules.size() << " module instances";
343
344
}

345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
std::vector<std::string> ModuleManager::get_type_vector(char* type_tokens) {
    std::vector<std::string> types;

    std::stringstream tokenstream(type_tokens);
    while(tokenstream.good()) {
        std::string token;
        getline(tokenstream, token, ',');
        if(token.empty()) {
            continue;
        }
        std::transform(token.begin(), token.end(), token.begin(), ::tolower);
        types.push_back(token);
    }
    return types;
}

361
362
363
364
365
366
367
std::shared_ptr<Detector> ModuleManager::get_detector(std::string name) {
    auto it = find_if(
        m_detectors.begin(), m_detectors.end(), [&name](std::shared_ptr<Detector> obj) { return obj->name() == name; });
    return (it != m_detectors.end() ? (*it) : nullptr);
}

std::pair<ModuleIdentifier, Module*> ModuleManager::create_unique_module(void* library, Configuration config) {
Simon Spannagel's avatar
Simon Spannagel committed
368
369
370
    // Create the identifier
    ModuleIdentifier identifier(config.getName(), "", 0);

371
372
373
374
375
376
377
378
    // Return error if user tried to specialize the unique module:
    if(config.has("name")) {
        throw InvalidValueError(config, "name", "unique modules cannot be specialized using the \"name\" keyword.");
    }
    if(config.has("type")) {
        throw InvalidValueError(config, "type", "unique modules cannot be specialized using the \"type\" keyword.");
    }

Simon Spannagel's avatar
Simon Spannagel committed
379
380
    LOG(TRACE) << "Creating module " << identifier.getUniqueName() << ", using generator \""
               << CORRYVRECKAN_GENERATOR_FUNCTION << "\"";
Simon Spannagel's avatar
Simon Spannagel committed
381
382
383
384
385

    // Get the generator function for this module
    void* generator = dlsym(library, CORRYVRECKAN_GENERATOR_FUNCTION);
    // If the generator function was not found, throw an error
    if(generator == nullptr) {
386
        LOG(ERROR) << "Module library is invalid or outdated: required "
Simon Spannagel's avatar
Simon Spannagel committed
387
                      "interface function not found!";
388
        throw corryvreckan::RuntimeError("Error instantiating module from " + config.getName());
Simon Spannagel's avatar
Simon Spannagel committed
389
    }
390

391
392
393
    // Create and add module instance config
    Configuration& instance_config = conf_manager_->addInstanceConfiguration(identifier, config);

Simon Spannagel's avatar
Simon Spannagel committed
394
    // Convert to correct generator function
395
396
    auto module_generator =
        reinterpret_cast<Module* (*)(Configuration, std::vector<std::shared_ptr<Detector>>)>(generator); // NOLINT
397

398
399
400
    // Set the log section header
    std::string old_section_name = Log::getSection();
    std::string section_name = "C:";
401
    section_name += identifier.getUniqueName();
402
403
    Log::setSection(section_name);
    // Set module specific log settings
404
    auto old_settings = set_module_before(identifier.getUniqueName(), instance_config);
405
    // Build module
406
    Module* module = module_generator(instance_config, m_detectors);
407
408
    // Reset log
    Log::setSection(old_section_name);
409
    set_module_after(old_settings);
410

411
    // Return the module to the analysis
Simon Spannagel's avatar
Simon Spannagel committed
412
    return std::make_pair(identifier, module);
413
414
}

Simon Spannagel's avatar
Simon Spannagel committed
415
std::vector<std::pair<ModuleIdentifier, Module*>>
416
ModuleManager::create_detector_modules(void* library, Configuration config, bool dut_only, std::vector<std::string> types) {
417
418
419
420
421
422
423
424
425
426
427
428
429
    LOG(TRACE) << "Creating instantiations for module " << config.getName() << ", using generator \""
               << CORRYVRECKAN_GENERATOR_FUNCTION << "\"";

    // Get the generator function for this module
    void* generator = dlsym(library, CORRYVRECKAN_GENERATOR_FUNCTION);
    // If the generator function was not found, throw an error
    if(generator == nullptr) {
        LOG(ERROR) << "Module library is invalid or outdated: required "
                      "interface function not found!";
        throw corryvreckan::RuntimeError("Error instantiating module from " + config.getName());
    }

    // Convert to correct generator function
430
    auto module_generator = reinterpret_cast<Module* (*)(Configuration, std::shared_ptr<Detector>)>(generator); // NOLINT
431
    auto module_base_name = config.getName();
432
433

    // Figure out which detectors should run on this module:
434
435
436
437
438
439
440
441
442
443
444
    bool instances_created = false;
    std::vector<std::pair<std::shared_ptr<Detector>, ModuleIdentifier>> instantiations;

    // Create all names first with highest priority
    std::set<std::string> module_names;
    if(config.has("name")) {
        std::vector<std::string> names = config.getArray<std::string>("name");
        for(auto& name : names) {
            auto det = get_detector(name);
            if(det == nullptr) {
                continue;
445
            }
446
447
448
449
450

            LOG(TRACE) << "Preparing \"name\" instance for " << det->name();
            instantiations.emplace_back(det, ModuleIdentifier(module_base_name, det->name(), 0));
            // Save the name (to not instantiate it again later)
            module_names.insert(name);
451
        }
452
        instances_created = !names.empty();
453
454
    }

455
456
457
458
459
460
461
    // Then create all types that are not yet name instantiated
    if(config.has("type")) {
        // Prepare type list from configuration:
        std::vector<std::string> ctypes = config.getArray<std::string>("type");
        for(auto& type : ctypes) {
            std::transform(type.begin(), type.end(), type.begin(), ::tolower);
        }
462

463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
        // Check that this is possible at all:
        std::vector<std::string> intersection;
        std::set_intersection(ctypes.begin(), ctypes.end(), types.begin(), types.end(), std::back_inserter(intersection));
        if(!types.empty() && intersection.empty()) {
            throw InvalidInstantiationError(module_base_name, "type conflict");
        }

        for(auto& det : m_detectors) {
            auto detectortype = det->type();
            std::transform(detectortype.begin(), detectortype.end(), detectortype.begin(), ::tolower);

            // Skip all that were already added by name
            if(module_names.find(det->name()) != module_names.end()) {
                continue;
            }
            for(auto& type : ctypes) {
                // Skip all with wrong type
                if(detectortype != type) {
                    continue;
                }

                LOG(TRACE) << "Preparing \"type\" instance for " << det->name();
                instantiations.emplace_back(det, ModuleIdentifier(module_base_name, det->name(), 1));
486
487
            }
        }
488
489
490
491
492
493
494
495
496
        instances_created = !ctypes.empty();
    }

    // Create for all detectors if no name / type provided
    if(!instances_created) {
        for(auto& det : m_detectors) {
            LOG(TRACE) << "Preparing \"other\" instance for " << det->name();
            instantiations.emplace_back(det, ModuleIdentifier(module_base_name, det->name(), 2));
        }
497
498
    }

Simon Spannagel's avatar
Simon Spannagel committed
499
    std::vector<std::pair<ModuleIdentifier, Module*>> modules;
500
501
502
503
    for(const auto& instance : instantiations) {
        auto detector = instance.first;
        auto identifier = instance.second;

504
505
        // If this should only be instantiated for DUTs, skip otherwise:
        if(dut_only && !detector->isDUT()) {
Simon Spannagel's avatar
Simon Spannagel committed
506
            LOG(TRACE) << "Skipping instantiation \"" << identifier.getUniqueName() << "\", detector is no DUT";
507
508
            continue;
        }
509
510
511
512
513
514
515
516

        // Do not instantiate module if detector type is not mentioned as supported:
        auto detectortype = detector->type();
        std::transform(detectortype.begin(), detectortype.end(), detectortype.begin(), ::tolower);
        if(!types.empty() && std::find(types.begin(), types.end(), detectortype) == types.end()) {
            LOG(TRACE) << "Skipping instantiation \"" << identifier.getUniqueName() << "\", detector type mismatch";
            continue;
        }
517
        LOG(DEBUG) << "Creating instantiation \"" << identifier.getUniqueName() << "\"";
518

519
520
521
        // Create and add module instance config
        Configuration& instance_config = conf_manager_->addInstanceConfiguration(instance.second, config);

522
523
524
        // Set the log section header
        std::string old_section_name = Log::getSection();
        std::string section_name = "C:";
Simon Spannagel's avatar
Simon Spannagel committed
525
        section_name += identifier.getUniqueName();
526
527
        Log::setSection(section_name);
        // Set module specific log settings
528
        auto old_settings = set_module_before(identifier.getUniqueName(), instance_config);
529
        // Build module
530
        modules.emplace_back(identifier, module_generator(instance_config, detector));
531
532
533
534
535
536
537
538
539
        // Reset log
        Log::setSection(old_section_name);
        set_module_after(old_settings);
    }

    // Return the list of modules to the analysis
    return modules;
}

540
// Run the analysis loop - this initialises, runs and finalises all modules
541
void ModuleManager::run() {
542
    Configuration& global_config = conf_manager_->getGlobalConfiguration();
Simon Spannagel's avatar
Simon Spannagel committed
543

544
    // Check if we have an event or track limit:
545
546
    auto number_of_events = global_config.get<int>("number_of_events", -1);
    auto number_of_tracks = global_config.get<int>("number_of_tracks", -1);
547
    auto run_time = global_config.get<double>("run_time", static_cast<double>(Units::convert(-1.0, "s")));
548

549
    // Loop over all events, running each module on each "event"
Simon Spannagel's avatar
Simon Spannagel committed
550
    LOG(STATUS) << "========================| Event loop |========================";
551
    m_events = 0;
552
553
    m_tracks = 0;

Simon Spannagel's avatar
Simon Spannagel committed
554
555
    while(1) {
        bool run = true;
556

Simon Spannagel's avatar
Simon Spannagel committed
557
        // Check if we have reached the maximum number of events
558

Simon Spannagel's avatar
Simon Spannagel committed
559
560
561
        if(number_of_events > -1 && m_events >= number_of_events)
            break;

562
        if(run_time > 0.0 && (m_clipboard->get_persistent("eventStart")) >= run_time)
563
564
            break;

565
566
567
568
        // Check if we have reached the maximum number of tracks
        if(number_of_tracks > -1 && m_tracks >= number_of_tracks)
            break;

569
570
        // Run all modules
        for(auto& module : m_modules) {
571
572
573
            // Get current time
            auto start = std::chrono::steady_clock::now();

574
575
576
            // Set run module section header
            std::string old_section_name = Log::getSection();
            std::string section_name = "R:";
Simon Spannagel's avatar
Simon Spannagel committed
577
            section_name += module->getUniqueName();
578
579
            Log::setSection(section_name);
            // Set module specific settings
Simon Spannagel's avatar
Simon Spannagel committed
580
            auto old_settings = set_module_before(module->getUniqueName(), module->getConfig());
Simon Spannagel's avatar
Simon Spannagel committed
581
            // Change to the output file directory
582
583
            module->getROOTDirectory()->cd();

584
            StatusCode check = module->run(m_clipboard);
585

586
587
            // Reset logging
            Log::setSection(old_section_name);
588
            set_module_after(old_settings);
589
590
591

            // Update execution time
            auto end = std::chrono::steady_clock::now();
592
            module_execution_time_[module.get()] += static_cast<std::chrono::duration<long double>>(end - start).count();
593

594
595
            if(check == StatusCode::DeadTime) {
                // If status code indicates dead time, just silently continue with next event:
596
                break;
597
598
599
600
601
602
            } else if(check == StatusCode::Failure) {
                // If the status code indicates failure, break immediately and finish:
                run = false;
                break;
            } else if(check == StatusCode::EndRun) {
                // If the returned status code asks for end-of-run, finish module list and finish:
Simon Spannagel's avatar
Simon Spannagel committed
603
                run = false;
604
            }
Simon Spannagel's avatar
Simon Spannagel committed
605
606
        }

607
        // Print statistics:
608
        Tracks* tracks = reinterpret_cast<Tracks*>(m_clipboard->get("tracks"));
609
        m_tracks += (tracks == nullptr ? 0 : static_cast<int>(tracks->size()));
610

611
        if(m_events % 100 == 0) {
612
613
614
615
616
617
618
619
620

            auto kilo_or_mega = [](const double& input) {
                bool mega = (input > 1e6 ? true : false);
                auto value = (mega ? input * 1e-6 : input * 1e-3);
                std::stringstream output;
                output << std::fixed << std::setprecision(mega ? 2 : 1) << value << (mega ? "M" : "k");
                return output.str();
            };

621
            LOG_PROGRESS(STATUS, "event_loop")
622
                << "Ev: " << kilo_or_mega(m_events) << " Tr: " << kilo_or_mega(m_tracks) << " (" << std::setprecision(3)
623
                << (static_cast<double>(m_tracks) / m_events) << "/ev)"
624
625
626
                << (m_clipboard->has_persistent("eventStart")
                        ? " t = " + Units::display(m_clipboard->get_persistent("eventStart"), {"ns", "us", "ms", "s"})
                        : "");
627
628
        }

Simon Spannagel's avatar
Simon Spannagel committed
629
630
        // Clear objects from this iteration from the clipboard
        m_clipboard->clear();
631

632
        // Check if any of the modules return a value saying it should stop
633
        if(!run) {
Simon Spannagel's avatar
Simon Spannagel committed
634
            break;
635
636
        }

Simon Spannagel's avatar
Simon Spannagel committed
637
        // Increment event number
638
        m_events++;
639
640
641

        // Check for user termination and stop the event loop:
        if(m_terminate) {
642
            break;
643
        }
644
645
646
    }
}

647
void ModuleManager::terminate() {
648
649
650
    m_terminate = true;
}

651
// Initalise all modules
652
void ModuleManager::initialiseAll() {
653
654
655
    // Loop over all modules and initialise them
    LOG(STATUS) << "=================| Initialising modules |==================";
    for(auto& module : m_modules) {
656
657
658
659
660
661
662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
677
678
679
680
681
682
        // Create main ROOT directory for this module class if it does not exists yet
        LOG(TRACE) << "Creating and accessing ROOT directory";
        std::string module_name = module->getConfig().getName();
        auto directory = m_histogramFile->GetDirectory(module_name.c_str());
        if(directory == nullptr) {
            directory = m_histogramFile->mkdir(module_name.c_str());
            if(directory == nullptr) {
                throw RuntimeError("Cannot create or access overall ROOT directory for module " + module_name);
            }
        }
        directory->cd();

        // Create local directory for this instance
        TDirectory* local_directory = nullptr;
        if(module->get_identifier().getIdentifier().empty()) {
            local_directory = directory;
        } else {
            local_directory = directory->mkdir(module->get_identifier().getIdentifier().c_str());
            if(local_directory == nullptr) {
                throw RuntimeError("Cannot create or access local ROOT directory for module " + module->getUniqueName());
            }
        }

        // Change to the directory and save it in the module
        local_directory->cd();
        module->set_ROOT_directory(local_directory);

683
684
685
        // Set init module section header
        std::string old_section_name = Log::getSection();
        std::string section_name = "I:";
Simon Spannagel's avatar
Simon Spannagel committed
686
        section_name += module->getUniqueName();
687
688
        Log::setSection(section_name);
        // Set module specific settings
Simon Spannagel's avatar
Simon Spannagel committed
689
        auto old_settings = set_module_before(module->getUniqueName(), module->getConfig());
690
691
        // Change to our ROOT directory
        module->getROOTDirectory()->cd();
692

693
        LOG_PROGRESS(STATUS, "MOD_INIT_LOOP") << "Initialising \"" << module->getUniqueName() << "\"";
694
695
        // Initialise the module
        module->initialise();
696
697
698

        // Reset logging
        Log::setSection(old_section_name);
699
        set_module_after(old_settings);
Simon Spannagel's avatar
Simon Spannagel committed
700
    }
701
702
}

703
// Finalise all modules
704
void ModuleManager::finaliseAll() {
705
    Configuration& global_config = conf_manager_->getGlobalConfiguration();
Simon Spannagel's avatar
Simon Spannagel committed
706

707
708
709
    // Loop over all modules and finalise them
    LOG(STATUS) << "===================| Finalising modules |===================";
    for(auto& module : m_modules) {
710
711
        // Set init module section header
        std::string old_section_name = Log::getSection();
Simon Spannagel's avatar
Simon Spannagel committed
712
        std::string section_name = "F:";
Simon Spannagel's avatar
Simon Spannagel committed
713
        section_name += module->getUniqueName();
714
715
        Log::setSection(section_name);
        // Set module specific settings
Simon Spannagel's avatar
Simon Spannagel committed
716
        auto old_settings = set_module_before(module->getUniqueName(), module->getConfig());
717
718
        // Change to our ROOT directory
        module->getROOTDirectory()->cd();
719

720
721
        // Finalise the module
        module->finalise();
722

723
724
725
        // Store all ROOT objects:
        module->getROOTDirectory()->Write();

726
727
728
        // Remove the pointer to the ROOT directory after finalizing
        module->set_ROOT_directory(nullptr);

729
730
        // Reset logging
        Log::setSection(old_section_name);
731
        set_module_after(old_settings);
Simon Spannagel's avatar
Simon Spannagel committed
732
    }
Simon Spannagel's avatar
Simon Spannagel committed
733

Simon Spannagel's avatar
Simon Spannagel committed
734
735
    // Write the output histogram file
    m_histogramFile->Close();
736

737
    LOG(STATUS) << "Wrote histogram output file to " << global_config.getPath("histogramFile");
738

739
740
741
742
743
744
745
746
747
748
    // Write out update detectors file:
    if(global_config.has("detectors_file_updated")) {
        std::string file_name = global_config.getPath("detectors_file_updated");
        // Check if the file exists
        std::ofstream file(file_name);
        if(!file) {
            throw ConfigFileUnavailableError(file_name);
        }

        ConfigReader final_detectors;
749
        for(auto& detector : m_detectors) {
750
751
752
753
754
755
756
            final_detectors.addConfiguration(detector->getConfiguration());
        }

        final_detectors.write(file);
        LOG(STATUS) << "Wrote updated detector configuration to " << file_name;
    }

Simon Spannagel's avatar
Simon Spannagel committed
757
758
    // Check the timing for all events
    timing();
759
760
}

761
// Display timing statistics for each module, over all events and per event
762
void ModuleManager::timing() {
763
    LOG(STATUS) << "===============| Wall-clock timing (seconds) |================";
764
    for(auto& module : m_modules) {
Simon Spannagel's avatar
Simon Spannagel committed
765
        auto identifier = module->get_identifier().getIdentifier();
766
        LOG(STATUS) << std::setw(20) << module->getConfig().getName() << (identifier.empty() ? "   " : " : ")
Simon Spannagel's avatar
Simon Spannagel committed
767
                    << std::setw(10) << identifier << "  --  " << std::fixed << std::setprecision(5)
768
769
                    << module_execution_time_[module.get()] << "s = " << std::setprecision(6)
                    << 1000 * module_execution_time_[module.get()] / m_events << "ms/evt";
Simon Spannagel's avatar
Simon Spannagel committed
770
    }
771
    LOG(STATUS) << "==============================================================";
772
}
773
774

// Helper functions to set the module specific log settings if necessary
775
std::tuple<LogLevel, LogFormat> ModuleManager::set_module_before(const std::string&, const Configuration& config) {
776
777
778
779
780
781
782
783
784
785
786
787
788
789
790
791
792
793
794
795
796
797
798
799
800
801
802
803
804
805
806
807
808
809
    // Set new log level if necessary
    LogLevel prev_level = Log::getReportingLevel();
    if(config.has("log_level")) {
        std::string log_level_string = config.get<std::string>("log_level");
        std::transform(log_level_string.begin(), log_level_string.end(), log_level_string.begin(), ::toupper);
        try {
            LogLevel log_level = Log::getLevelFromString(log_level_string);
            if(log_level != prev_level) {
                LOG(TRACE) << "Local log level is set to " << log_level_string;
                Log::setReportingLevel(log_level);
            }
        } catch(std::invalid_argument& e) {
            throw InvalidValueError(config, "log_level", e.what());
        }
    }

    // Set new log format if necessary
    LogFormat prev_format = Log::getFormat();
    if(config.has("log_format")) {
        std::string log_format_string = config.get<std::string>("log_format");
        std::transform(log_format_string.begin(), log_format_string.end(), log_format_string.begin(), ::toupper);
        try {
            LogFormat log_format = Log::getFormatFromString(log_format_string);
            if(log_format != prev_format) {
                LOG(TRACE) << "Local log format is set to " << log_format_string;
                Log::setFormat(log_format);
            }
        } catch(std::invalid_argument& e) {
            throw InvalidValueError(config, "log_format", e.what());
        }
    }

    return std::make_tuple(prev_level, prev_format);
}
810
void ModuleManager::set_module_after(std::tuple<LogLevel, LogFormat> prev) {
811
812
813
814
815
816
817
818
819
820
821
822
823
824
825
826
    // Reset the previous log level
    LogLevel cur_level = Log::getReportingLevel();
    LogLevel old_level = std::get<0>(prev);
    if(cur_level != old_level) {
        Log::setReportingLevel(old_level);
        LOG(TRACE) << "Reset log level to global level of " << Log::getStringFromLevel(old_level);
    }

    // Reset the previous log format
    LogFormat cur_format = Log::getFormat();
    LogFormat old_format = std::get<1>(prev);
    if(cur_format != old_format) {
        Log::setFormat(old_format);
        LOG(TRACE) << "Reset log format to global level of " << Log::getStringFromFormat(old_format);
    }
}
827

828
void ModuleManager::add_units() {
829
830
831
832
833
834
835
836
837
838
839
840
841
842
843
844
845
846
847
848
849
850
851
852
853
854
855
856
857
858
859
860
861
862
863
864
865
866
867
868
869
870
871
872

    LOG(TRACE) << "Adding physical units";

    // LENGTH
    Units::add("nm", 1e-6);
    Units::add("um", 1e-3);
    Units::add("mm", 1);
    Units::add("cm", 1e1);
    Units::add("dm", 1e2);
    Units::add("m", 1e3);
    Units::add("km", 1e6);

    // TIME
    Units::add("ps", 1e-3);
    Units::add("ns", 1);
    Units::add("us", 1e3);
    Units::add("ms", 1e6);
    Units::add("s", 1e9);

    // TEMPERATURE
    Units::add("K", 1);

    // ENERGY
    Units::add("eV", 1e-6);
    Units::add("keV", 1e-3);
    Units::add("MeV", 1);
    Units::add("GeV", 1e3);

    // CHARGE
    Units::add("e", 1);
    Units::add("ke", 1e3);
    Units::add("C", 1.6021766208e-19);

    // VOLTAGE
    // NOTE: fixed by above
    Units::add("V", 1e-6);
    Units::add("kV", 1e-3);

    // ANGLES
    // NOTE: these are fake units
    Units::add("deg", 0.01745329252);
    Units::add("rad", 1);
    Units::add("mrad", 1e-3);
}