Commit 44092096 authored by Simon Spannagel's avatar Simon Spannagel
Browse files

ModuleManager: for event frequency only use run() timing

(cherry picked from commit f8ef274f)
parent 7f20be7a
Loading
Loading
Loading
Loading
+7 −6
Original line number Diff line number Diff line
@@ -628,7 +628,7 @@ void ModuleManager::initialize() {
    }
    LOG_PROGRESS(STATUS, "INIT_LOOP") << "Initialized " << modules_.size() << " module instantiations";
    auto end_time = std::chrono::steady_clock::now();
    total_time_ += static_cast<std::chrono::duration<long double>>(end_time - start_time).count();
    initialize_time_ = static_cast<std::chrono::duration<long double>>(end_time - start_time).count();
}

/**
@@ -879,7 +879,7 @@ void ModuleManager::run(RandomNumberGenerator& seeder) {
    global_config.set<uint64_t>("number_of_events", finished_events);

    auto end_time = std::chrono::steady_clock::now();
    total_time_ += static_cast<std::chrono::duration<long double>>(end_time - start_time).count();
    run_time_ = static_cast<std::chrono::duration<long double>>(end_time - start_time).count();

    LOG(TRACE) << "Destroying thread pool";
    thread_pool_.reset();
@@ -970,7 +970,8 @@ void ModuleManager::finalize() {
    modules_file_->Close();
    LOG_PROGRESS(STATUS, "FINALIZE_LOOP") << "Finalization completed";
    auto end_time = std::chrono::steady_clock::now();
    total_time_ += static_cast<std::chrono::duration<long double>>(end_time - start_time).count();
    finalize_time_ = static_cast<std::chrono::duration<long double>>(end_time - start_time).count();
    auto total_time = initialize_time_ + run_time_ + finalize_time_;

    // Check for unused configuration keys:
    auto unused_keys = global_config.getUnusedKeys();
@@ -1010,7 +1011,7 @@ void ModuleManager::finalize() {
            slowest_module = module_time.first->getUniqueName();
        }
    }
    LOG(STATUS) << "Executed " << modules_.size() << " instantiations in " << seconds_to_time(total_time_) << ", spending "
    LOG(STATUS) << "Executed " << modules_.size() << " instantiations in " << seconds_to_time(total_time) << ", spending "
                << std::round((100 * slowest_time) / std::max(1.0l, total_module_time))
                << "% of time in slowest instantiation " << slowest_module;
    for(auto& module : modules_) {
@@ -1020,11 +1021,11 @@ void ModuleManager::finalize() {
    long double processing_time = 0;
    auto total_events = global_config.get<uint64_t>("number_of_events");
    if(total_events > 0) {
        processing_time = std::round((1000 * total_time_) / total_events);
        processing_time = std::round((1000 * run_time_) / total_events);
    }

    LOG(STATUS) << "Average processing time is \x1B[1m" << processing_time << " ms/event\x1B[0m, event generation at \x1B[1m"
                << std::round(global_config.get<double>("number_of_events") / total_time_) << " Hz\x1B[0m";
                << std::round(global_config.get<double>("number_of_events") / run_time_) << " Hz\x1B[0m";

    if(global_config.get<unsigned int>("workers") > 0) {
        auto event_processing_time = std::round(processing_time * global_config.get<unsigned int>("workers"));
+1 −1
Original line number Diff line number Diff line
@@ -161,7 +161,7 @@ namespace allpix {
        Histogram<TH1D> event_time_;
        Histogram<TH1D> buffer_fill_level_;

        long double total_time_{};
        long double initialize_time_{}, run_time_{}, finalize_time_{};

        std::map<std::string, void*> loaded_libraries_;