Analysis.C 19.6 KB
Newer Older
1
// ROOT include files
2
#include <TSystem.h>
Simon Spannagel's avatar
Simon Spannagel committed
3
#include "TFile.h"
4
5
6

// Local include files
#include "Analysis.h"
Simon Spannagel's avatar
Simon Spannagel committed
7
#include "objects/Timepix3Track.h"
8
#include "utils/log.h"
9

10
11
12
13
#include <dlfcn.h>
#include <fstream>

#define CORRYVRECKAN_ALGORITHM_PREFIX "libCorryvreckanAlgorithm"
14
#define CORRYVRECKAN_GENERATOR_FUNCTION "corryvreckan_algorithm_generator"
15

16
17
using namespace corryvreckan;

18
// Default constructor
19
Analysis::Analysis(std::string config_file_name) : m_terminate(false) {
20

Simon Spannagel's avatar
Simon Spannagel committed
21
22
    // Load the global configuration
    conf_mgr_ = std::make_unique<corryvreckan::ConfigManager>(std::move(config_file_name));
23

Simon Spannagel's avatar
Simon Spannagel committed
24
25
26
27
    // Configure the standard special sections
    conf_mgr_->setGlobalHeaderName("Corryvreckan");
    conf_mgr_->addGlobalHeaderName("");
    conf_mgr_->addIgnoreHeaderName("Ignore");
28

Simon Spannagel's avatar
Simon Spannagel committed
29
    // Fetch the global configuration
Simon Spannagel's avatar
Simon Spannagel committed
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
    global_config = conf_mgr_->getGlobalConfiguration();

    // 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;
71

Simon Spannagel's avatar
Simon Spannagel committed
72
73
    // FIXME translate new configuration to parameters:
    m_parameters = new Parameters();
74

Simon Spannagel's avatar
Simon Spannagel committed
75
    // Define DUT and reference
Simon Spannagel's avatar
Simon Spannagel committed
76
77
    m_parameters->DUT = global_config.get<std::string>("DUT");
    m_parameters->reference = global_config.get<std::string>("reference");
78

Simon Spannagel's avatar
Simon Spannagel committed
79
80
    m_parameters->detectorToAlign = m_parameters->DUT;
    m_parameters->excludedFromTracking[m_parameters->DUT] = true;
81

82
83
84
85
86
    if(global_config.has("excludeFromTracking")) {
        std::vector<std::string> excluding = global_config.getArray<std::string>("excludeFromTracking");
        for(auto& ex : excluding) {
            m_parameters->excludedFromTracking[ex] = true;
        }
Simon Spannagel's avatar
Simon Spannagel committed
87
    }
88

Simon Spannagel's avatar
Simon Spannagel committed
89
    std::vector<std::string> masking = global_config.getArray<std::string>("masked");
Simon Spannagel's avatar
Simon Spannagel committed
90
91
92
    for(auto& m : masking) {
        m_parameters->masked[m] = true;
    }
93

Simon Spannagel's avatar
Simon Spannagel committed
94
95
96
97
98
    // FIXME Read remaining parametes from command line:
    // Overwrite steering file values from command line
    // parameters->readCommandLineOptions(argc,argv);

    // Load alignment parameters
Simon Spannagel's avatar
Simon Spannagel committed
99
    std::string conditionsFile = global_config.get<std::string>("conditionsFile");
Simon Spannagel's avatar
Simon Spannagel committed
100
101
102
103
104
    m_parameters->conditionsFile = conditionsFile;
    if(!m_parameters->readConditions())
        throw ConfigFileUnavailableError(conditionsFile);

    // Load mask file for the dut (if specified)
Simon Spannagel's avatar
Simon Spannagel committed
105
    m_parameters->dutMaskFile = global_config.get<std::string>("dutMaskFile", "defaultMask.dat");
Simon Spannagel's avatar
Simon Spannagel committed
106
107
108
109
110
111
112
113
114
115
116
    m_parameters->readDutMask();

    // FIXME per-algorithm settings:
    //   basicTracking->minHitsOnTrack = 7;
    // clicpixAnalysis->timepix3Telescope = true;
    //  spatialTracking->debug = true;
    // testAlgorithm->makeCorrelations = true;
    // dataDump->m_detector = parameters->DUT;

    // New clipboard for storage:
    m_clipboard = new Clipboard();
117
118
119
}

// Add an algorithm to the list of algorithms to run
Simon Spannagel's avatar
Simon Spannagel committed
120
121
void Analysis::add(Algorithm* algorithm) {
    m_algorithms.push_back(algorithm);
122
123
}

124
125
void Analysis::load() {

Simon Spannagel's avatar
Simon Spannagel committed
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
    std::vector<Configuration> configs = conf_mgr_->getConfigurations();

    // Create histogram output file
    m_histogramFile = new TFile(m_parameters->histogramFile.c_str(), "RECREATE");
    m_directory = m_histogramFile->mkdir("corryvreckan");
    if(m_histogramFile->IsZombie()) {
        throw RuntimeError("Cannot create main ROOT file " + std::string(m_parameters->histogramFile.c_str()));
    }

    LOG(DEBUG) << "Start loading algorithms, have " << configs.size() << " configurations.";
    // Loop through all non-global configurations
    for(auto& config : configs) {
        // Load library for each module. Libraries are named (by convention + CMAKE)
        // libAllpixModule Name.suffix
        std::string lib_name =
            std::string(CORRYVRECKAN_ALGORITHM_PREFIX).append(config.getName()).append(SHARED_LIBRARY_SUFFIX);
        LOG_PROGRESS(STATUS, "LOAD_LOOP") << "Loading algorithm " << config.getName();

        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
150
151
            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
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
                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;
                }
191
192
            }
        } else {
Simon Spannagel's avatar
Simon Spannagel committed
193
194
            // Otherwise just fetch it from the cache
            lib = loaded_libraries_[lib_name];
195
196
        }

Simon Spannagel's avatar
Simon Spannagel committed
197
198
199
        // If library did not load then throw exception
        if(load_error) {
            const char* lib_error = dlerror();
200

Simon Spannagel's avatar
Simon Spannagel committed
201
202
203
204
205
206
207
            // 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);
            }
208

Simon Spannagel's avatar
Simon Spannagel committed
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
            // 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 &&
                      problem_lib.find(CORRYVRECKAN_ALGORITHM_PREFIX) == std::string::npos) {
                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;
                }
            }
232

Simon Spannagel's avatar
Simon Spannagel committed
233
234
235
236
            throw corryvreckan::RuntimeError("Error loading " + config.getName());
        }
        // Remember that this library was loaded
        loaded_libraries_[lib_name] = lib;
237

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

Simon Spannagel's avatar
Simon Spannagel committed
242
243
244
245
        // Create the algorithms from the library
        m_algorithms.emplace_back(create_algorithm(loaded_libraries_[lib_name], config, m_clipboard));
    }
    LOG_PROGRESS(STATUS, "LOAD_LOOP") << "Loaded " << configs.size() << " modules";
246
247
248
}

Algorithm* Analysis::create_algorithm(void* library, Configuration config, Clipboard* clipboard) {
Simon Spannagel's avatar
Simon Spannagel committed
249
250
251
252
253
254
255
256
257
258
259
260
261
262
    LOG(TRACE) << "Creating algorithm " << config.getName() << ", using generator \"" << CORRYVRECKAN_GENERATOR_FUNCTION
               << "\"";

    // Make the vector to return
    std::string algorithm_name = config.getName();

    // 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) << "Algorithm library is invalid or outdated: required "
                      "interface function not found!";
        throw corryvreckan::RuntimeError("Error instantiating algorithm from " + config.getName());
    }
263

Simon Spannagel's avatar
Simon Spannagel committed
264
265
    // Convert to correct generator function
    auto algorithm_generator = reinterpret_cast<Algorithm* (*)(Configuration, Clipboard*)>(generator); // NOLINT
266

267
268
269
270
271
272
273
    // Set the log section header
    std::string old_section_name = Log::getSection();
    std::string section_name = "C:";
    section_name += config.getName();
    Log::setSection(section_name);
    // Set module specific log settings
    auto old_settings = set_algorithm_before(config.getName(), config);
Simon Spannagel's avatar
Simon Spannagel committed
274
275
    // Build algorithm
    Algorithm* algorithm = algorithm_generator(config, clipboard);
276
277
278
    // Reset log
    Log::setSection(old_section_name);
    set_algorithm_after(old_settings);
279

Simon Spannagel's avatar
Simon Spannagel committed
280
281
    // Return the algorithm to the analysis
    return algorithm;
282
283
}

284
// Run the analysis loop - this initialises, runs and finalises all algorithms
Simon Spannagel's avatar
Simon Spannagel committed
285
286
void Analysis::run() {

287
    // Check if we have an event limit:
Simon Spannagel's avatar
Simon Spannagel committed
288
    int number_of_events = global_config.get<int>("number_of_events", 0);
289

Simon Spannagel's avatar
Simon Spannagel committed
290
291
292
293
294
295
    // Loop over all events, running each algorithm on each "event"
    LOG(STATUS) << "========================| Event loop |========================";
    m_events = 1;
    while(1) {
        bool run = true;
        bool noData = false;
296

Simon Spannagel's avatar
Simon Spannagel committed
297
        // Run all algorithms
298
299
300
301
302
303
304
305
        for(auto& algorithm : m_algorithms) {
            // Set run module section header
            std::string old_section_name = Log::getSection();
            std::string section_name = "R:";
            section_name += algorithm->getName();
            Log::setSection(section_name);
            // Set module specific settings
            auto old_settings = set_algorithm_before(algorithm->getName(), algorithm->getConfig());
Simon Spannagel's avatar
Simon Spannagel committed
306
            // Change to the output file directory
307
            m_directory->cd(algorithm->getName().c_str());
Simon Spannagel's avatar
Simon Spannagel committed
308
            // Run the algorithms with timing enabled
309
310
311
312
313
314
            algorithm->getStopwatch()->Start(false);
            StatusCode check = algorithm->run(m_clipboard);
            algorithm->getStopwatch()->Stop();
            // Reset logging
            Log::setSection(old_section_name);
            set_algorithm_after(old_settings);
Simon Spannagel's avatar
Simon Spannagel committed
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
            if(check == NoData) {
                noData = true;
                break;
            } // Nothing to be done in this event
            if(check == Failure)
                run = false;
        }
        // Count number of tracks produced
        //    Timepix3Tracks* tracks =
        //    (Timepix3Tracks*)m_clipboard->get("Timepix3","tracks");
        //    if(tracks != NULL) nTracks += tracks->size();

        //    LOG(DEBUG) << "\r[Analysis] Current time is
        //    "<<fixed<<setw(10)<<m_parameters->currentTime<<". Produced
        //    "<<nTracks<<" tracks"<<flush;

        // Clear objects from this iteration from the clipboard
        m_clipboard->clear();
        // Check if any of the algorithms return a value saying it should stop
        if(!run)
            break;
        // Check if we have reached the maximum number of events
337
        if(number_of_events > 0 && m_events >= number_of_events)
Simon Spannagel's avatar
Simon Spannagel committed
338
339
340
341
            break;
        // Increment event number
        if(!noData)
            m_events++;
342
343
344
345
346

        // Check for user termination and stop the event loop:
        if(m_terminate) {
          break;
        }
347
    }
Simon Spannagel's avatar
Simon Spannagel committed
348
349

    // If running the gui, don't close until the user types a command
Simon Spannagel's avatar
Simon Spannagel committed
350
    if(global_config.get<bool>("gui", false))
351
        std::cin.ignore();
352
353
}

354
355
356
357
void Analysis::terminate() {
    m_terminate = true;
}

358
// Initalise all algorithms
Simon Spannagel's avatar
Simon Spannagel committed
359
360
361
362
363
void Analysis::initialiseAll() {
    int nTracks = 0;

    // Loop over all algorithms and initialise them
    LOG(STATUS) << "=================| Initialising algorithms |==================";
364
365
366
367
368
369
370
371
372
    for(auto& algorithm : m_algorithms) {
        // Set init module section header
        std::string old_section_name = Log::getSection();
        std::string section_name = "I:";
        section_name += algorithm->getName();
        Log::setSection(section_name);
        // Set module specific settings
        auto old_settings = set_algorithm_before(algorithm->getName(), algorithm->getConfig());

Simon Spannagel's avatar
Simon Spannagel committed
373
374
        // Make a new folder in the output file
        m_directory->cd();
375
376
377
        m_directory->mkdir(algorithm->getName().c_str());
        m_directory->cd(algorithm->getName().c_str());
        LOG(INFO) << "Initialising \"" << algorithm->getName() << "\"";
Simon Spannagel's avatar
Simon Spannagel committed
378
        // Initialise the algorithm
379
380
381
382
383
        algorithm->initialise(m_parameters);

        // Reset logging
        Log::setSection(old_section_name);
        set_algorithm_after(old_settings);
Simon Spannagel's avatar
Simon Spannagel committed
384
    }
385
386
387
}

// Finalise all algorithms
Simon Spannagel's avatar
Simon Spannagel committed
388
389
390
void Analysis::finaliseAll() {

    // Loop over all algorithms and finalise them
391
392
393
394
395
396
397
398
399
    for(auto& algorithm : m_algorithms) {
        // Set init module section header
        std::string old_section_name = Log::getSection();
        std::string section_name = "I:";
        section_name += algorithm->getName();
        Log::setSection(section_name);
        // Set module specific settings
        auto old_settings = set_algorithm_before(algorithm->getName(), algorithm->getConfig());

Simon Spannagel's avatar
Simon Spannagel committed
400
        // Change to the output file directory
401
        m_directory->cd(algorithm->getName().c_str());
Simon Spannagel's avatar
Simon Spannagel committed
402
        // Finalise the algorithm
403
404
405
406
        algorithm->finalise();
        // Reset logging
        Log::setSection(old_section_name);
        set_algorithm_after(old_settings);
Simon Spannagel's avatar
Simon Spannagel committed
407
    }
Simon Spannagel's avatar
Simon Spannagel committed
408

Simon Spannagel's avatar
Simon Spannagel committed
409
410
411
412
    // Write the output histogram file
    m_directory->cd();
    m_directory->Write();
    m_histogramFile->Close();
413

Simon Spannagel's avatar
Simon Spannagel committed
414
415
    // Check the timing for all events
    timing();
416
417
418
}

// Display timing statistics for each algorithm, over all events and per event
Simon Spannagel's avatar
Simon Spannagel committed
419
420
void Analysis::timing() {
    LOG(INFO) << "===============| Wall-clock timing (seconds) |================";
421
422
423
424
    for(auto& algorithm : m_algorithms) {
        LOG(INFO) << algorithm->getName() << "  --  "
                  << algorithm->getStopwatch()->RealTime() << " = "
                  << algorithm->getStopwatch()->RealTime() / m_events << " s/evt";
Simon Spannagel's avatar
Simon Spannagel committed
425
426
    }
    LOG(INFO) << "==============================================================";
427
}
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481

// Helper functions to set the module specific log settings if necessary
std::tuple<LogLevel, LogFormat> Analysis::set_algorithm_before(const std::string&, const Configuration& config) {
    // 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);
}
void Analysis::set_algorithm_after(std::tuple<LogLevel, LogFormat> prev) {
    // 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);
    }
}